def _read_next_failed_past_due_task(self):
min_fail_end_date = date_minus_seconds(date_now(), MAX_FAIL_DUE_TIME)
q = { "state": STATE_FAILED,
"engineGuid": self._engine.engine_guid,
"$or": [
{
"plan.nextOccurrence": {"$lte": date_now()}
},
{
"plan": {"$exists": False},
"reschedulable": False,
"endDate": {"$lte": min_fail_end_date}
}
]
}
msg = "Task failed and is past due. Cancelling..."
log_entry = state_change_log_entry(STATE_CANCELED, message=msg)
u = {"$set" : { "state" : STATE_CANCELED},
"$push": {
"logs": log_entry.to_document()
}
}
return self._task_collection.find_and_modify(query=q, update=u,
new=True)
def _read_next_failed_past_due_task(self):
min_fail_end_date = date_minus_seconds(date_now(), MAX_FAIL_DUE_TIME)
q = {
"$or": [
{
"state": State.FAILED,
"engineGuid": self._engine.engine_guid,
"nextRetryDate": None,
"finalRetryDate": {"$lte": date_now()},
"plan.nextOccurrence": {"$lte": date_now()}
},
{
"state": State.FAILED,
"engineGuid": self._engine.engine_guid,
"plan": {"$exists": False},
"nextRetryDate": None,
"finalRetryDate": {"$lte": min_fail_end_date}
}
]
}
msg = "Task failed and is past due. Cancelling..."
log_entry = state_change_log_entry(State.CANCELED, message=msg)
u = {"$set" : { "state" : State.CANCELED},
"$push": {
"logs": log_entry.to_document()
}
}
task = self.task_collection.find_one(query=q)
if task:
return self.task_collection.find_and_modify(query=q, update=u, new=True)
def _process_plans_considered_now(self, process_max_count=None):
count = 0
start_date = date_now()
for plan in self._get_plans_to_consider_now(limit=process_max_count):
self._plans_queue.put(plan)
if process_max_count:
count += 1
if count >= process_max_count:
break
# wait for workers to finish
self._plans_queue.join()
if count:
time_elapsed = timedelta_total_seconds(date_now() - start_date)
logger.info("Finished processing %s plans in %s seconds" % ((count or "all"), time_elapsed))
def _process_plans_considered_now(self, process_max_count=None):
count = 0
start_date = date_now()
for plan in self._get_plans_to_consider_now(limit=process_max_count):
self._plans_queue.put(plan)
if process_max_count:
count += 1
if count >= process_max_count:
break
# wait for workers to finish
self._plans_queue.join()
if count:
time_elapsed = timedelta_total_seconds(date_now() - start_date)
logger.info("Finished processing %s plans in %s seconds" %
((count or "all"), time_elapsed))
def save_plan(self, plan):
try:
self.debug("Validating plan %s" % plan)
errors = plan.validate()
if errors:
err_msg = ("Plan %s is invalid."
"Please correct the following errors and then try"
" saving again.\n%s" % (plan, errors))
raise BackupSystemError(err_msg)
# set plan created date if its not set
if not plan.created_date:
plan.created_date = date_now()
is_new_plan = not plan.id
if is_new_plan:
self.info("Saving new plan: \n%s" % plan)
plan_doc = plan.to_document()
get_mbs().plan_collection.save_document(plan_doc)
plan.id = plan_doc["_id"]
self.info("Plan saved successfully")
else:
self.info("Updating plan: \n%s" % plan)
self.update_existing_plan(plan)
self.info("Plan updated successfully")
except Exception, e:
raise BackupSystemError("Error while saving plan %s. %s" %
(plan, e))
def _cancel_past_cycle_backups(self):
"""
Cancels scheduled backups (or backups failed to be scheduled,
i.e. engine guid is none) whose plan's next occurrence in in the past
"""
now = date_now()
q = {
"state": {
"$in": [State.SCHEDULED, State.FAILED]
},
"plan.nextOccurrence": {
"$lte": now
},
"engineGuid": None
}
bc = get_mbs().backup_collection
for backup in bc.find(q):
logger.info("Cancelling backup %s" % backup.id)
backup.state = State.CANCELED
bc.update_task(backup,
properties="state",
event_name=EVENT_STATE_CHANGE,
message="Backup is past due. Canceling...")
def _get_plans_to_consider_now(self, limit=None):
"""
Returns list of plans that the scheduler should process at this time.
Those are:
1- Plans with no backups scheduled yet (next occurrence has not
been calculated yet)
2- Plans whose next occurrence is now or in the past
"""
now = date_now()
q = {
"$or": [{
"nextOccurrence": None
}, {
"nextOccurrence": {
"$lte": now
}
}]
}
# sort by priority
s = [("priority", 1)]
return get_mbs().plan_collection.find_iter(q, sort=s, limit=limit)
def _recover(self):
"""
Does necessary recovery work on crashes. Fails all tasks that crashed
while in progress and makes them reschedulable. Backup System will
decide to cancel them or reschedule them.
"""
self.info("Running recovery..")
q = {
"state": STATE_IN_PROGRESS,
"engineGuid": self._engine.engine_guid
}
total_crashed = 0
msg = ("Engine crashed while task was in progress. Failing...")
for task in self._task_collection.find(q):
# fail task
self.info("Recovery: Failing task %s" % task._id)
task.reschedulable = True
task.state = STATE_FAILED
task.end_date = date_now()
# update
self._task_collection.update_task(task,
properties=["state",
"reschedulable",
"endDate"],
event_type=EVENT_STATE_CHANGE,
message=msg)
total_crashed += 1
self.info("Recovery complete! Total Crashed task: %s." %
total_crashed)
def last_natural_occurrence(self, dt=None):
dt = date_now() if dt is None else dt
date_seconds = date_to_seconds(dt)
offset = self.offset if self.offset else epoch_date()
offset_seconds = date_to_seconds(offset)
return seconds_to_date(date_seconds - ((date_seconds - offset_seconds) % self.frequency_in_seconds))
def _recover(self):
"""
Does necessary recovery work on crashes. Fails all tasks that crashed
while in progress and makes them reschedulable. Backup System will
decide to cancel them or reschedule them.
"""
self.info("Running recovery..")
q = {
"state": STATE_IN_PROGRESS,
"engineGuid": self._engine.engine_guid
}
total_crashed = 0
msg = ("Engine crashed while task was in progress. Failing...")
for task in self._task_collection.find(q):
# fail task
self.info("Recovery: Failing task %s" % task._id)
task.reschedulable = True
task.state = STATE_FAILED
task.end_date = date_now()
# update
self._task_collection.update_task(
task,
properties=["state", "reschedulable", "endDate"],
event_type=EVENT_STATE_CHANGE,
message=msg)
total_crashed += 1
self.info("Recovery complete! Total Crashed task: %s." % total_crashed)
def _get_plans_to_consider_now(self):
"""
Returns list of plans that the scheduler should process at this time.
Those are:
1- Plans with no backups scheduled yet (next occurrence has not
been calculated yet)
2- Plans whose next occurrence is now or in the past
"""
now = date_now()
q = {
"$or": [{
"nextOccurrence": {
"$exists": False
}
}, {
"nextOccurrence": None
}, {
"nextOccurrence": {
"$lte": now
}
}]
}
return get_mbs().plan_collection.find(q)
def reschedule_backup(self, backup, from_scratch=False):
"""
Reschedules the backup IF backup state is FAILED and
backup is still within it's plan current cycle
"""
if backup.state != STATE_FAILED:
msg = ("Cannot reschedule backup ('%s', '%s'). Rescheduling is "
"only allowed for backups whose state is '%s'." %
(backup.id, backup.state, STATE_FAILED))
raise BackupSystemError(msg)
elif backup.plan and backup.plan.next_occurrence <= date_now():
msg = ("Cannot reschedule backup '%s' because its occurrence is"
" in the past of the current cycle" % backup.id)
raise BackupSystemError(msg)
self.info("Rescheduling backup %s" % backup._id)
backup.state = STATE_SCHEDULED
# regenerate backup tags if backup belongs to a plan
if backup.plan:
backup.tags = backup.plan.generate_tags()
bc = get_mbs().backup_collection
# if from_scratch is set then clear backup log
if from_scratch:
backup.logs = []
backup.try_count = 0
backup.engine_guid = None
bc.update_task(backup,
properties=["logs", "tryCount", "engineGuid"])
bc.update_task(backup,
properties=["state", "tags"],
event_name=EVENT_STATE_CHANGE,
message="Rescheduling")
def do_delete_target_ref(backup, target, target_ref):
if target_ref.preserve:
logger.info("Skipping deletion for target ref %s (backup '%s') because"
" it is preserved" % (target_ref, backup.id))
return
try:
target_ref.deleted_date = date_now()
# if the target reference is a cloud storage one then make the cloud
# storage object take care of it
if isinstance(target_ref, CloudBlockStorageSnapshotReference):
logger.info("Deleting backup '%s' snapshot " % backup.id)
return target_ref.cloud_block_storage.delete_snapshot(target_ref)
else:
logger.info("Deleting backup '%s file" % backup.id)
return target.delete_file(target_ref)
except TargetInaccessibleError as e:
msg = "Target %s for backup %s is no longer accessible.\n%s" % (
target, backup.id, e.message
)
logger.warn(msg)
persistence.update_backup(backup,
event_name="DELETE_ERROR",
message=msg,
event_type=EventType.WARNING)
return False
def delete_backup_targets(self, backup):
logger.info("Attempt to delete targets for backup '%s'" % backup.id)
self.validate_backup_target_delete(backup)
try:
if not self.test_mode:
robustified_delete_backup(backup)
return True
else:
logger.info("NOOP. Running in test mode. Not deleting "
"targets for backup '%s'" % backup.id)
except Exception, e:
msg = "Error while attempting to expire backup '%s': " % e
logger.exception(msg)
# if the backup expiration has errored out for 5 times (including this time) then mark as deleted
if backup.event_logged_count("DELETE_ERROR") > 5:
msg = ("Giving up on delete backup '%s'. Failed at least 5 times. Marking backup as deleted" %
backup.id)
logger.warning(msg)
# set deleted date
backup.deleted_date = date_now()
persistence.update_backup(backup,
event_name="DELETE_ERROR",
message=msg,
properties=["deletedDate"],
event_type=EventType.ERROR)
def filter_backups_due_for_expiration(self, backups):
earliest_date_to_keep = date_minus_seconds(date_now(), self.max_time)
return filter(lambda backup:
backup.created_date < earliest_date_to_keep,
backups)
def last_natural_occurrence(self, dt=None):
dt = date_now() if dt is None else dt
date_seconds = date_to_seconds(dt)
offset = self.offset if self.offset else epoch_date()
offset_seconds = date_to_seconds(offset)
return seconds_to_date(date_seconds - (
(date_seconds - offset_seconds) % self.frequency_in_seconds))
def max_acceptable_lag(self, dt=None):
dt = date_now() if dt is None else dt
if self._is_occurrence(dt):
# we are concerned with the period leading up to dt
return self._max_acceptable_lag_for_period(dt - self.last_natural_occurrence(dt - timedelta(minutes=1)))
# otherwise we are concerned with the period leading up to the next
# occurrence
return self._max_acceptable_lag_for_period(self.next_natural_occurrence(dt) - self.last_natural_occurrence(dt))
def schedule_backup(self, **kwargs):
try:
backup = Backup()
backup.created_date = date_now()
backup.strategy = get_validate_arg(kwargs,
"strategy",
expected_type=BackupStrategy)
backup.source = get_validate_arg(kwargs, "source", BackupSource)
backup.target = get_validate_arg(kwargs, "target", BackupTarget)
backup.priority = get_validate_arg(kwargs,
"priority",
expected_type=(int, long, float,
complex),
required=False)
backup.plan_occurrence = \
get_validate_arg(kwargs, "plan_occurrence",
expected_type=datetime,
required=False)
backup.plan = get_validate_arg(kwargs,
"plan",
expected_type=BackupPlan,
required=False)
backup.secondary_targets = get_validate_arg(kwargs,
"secondary_targets",
expected_type=list,
required=False)
backup.change_state(State.SCHEDULED)
# set tags
tags = get_validate_arg(kwargs,
"tags",
expected_type=dict,
required=False)
backup.tags = tags
bc = get_mbs().backup_collection
try:
# resolve tags
self._resolve_task_tags(backup)
except Exception, ex:
self._task_failed_to_schedule(backup, bc, ex)
backup_doc = backup.to_document()
get_mbs().backup_collection.save_document(backup_doc)
# set the backup id from the saved doc
backup.id = backup_doc["_id"]
self.info("Saved backup \n%s" % backup)
if backup.state == State.FAILED:
trigger_task_finished_event(backup, State.FAILED)
return backup
def _process_failed_backups(self):
"""
Reschedule failed backups that failed and are retriable
"""
q = {"state": State.FAILED, "nextRetryDate": {"$lt": date_now()}}
for backup in get_mbs().backup_collection.find(q):
self._process_failed_backup(backup)
def last_n_occurrences(self, n, dt=None):
end_date = dt or date_now()
occurrences = []
for i in range(0, n):
occurrence = self.last_natural_occurrence(dt=end_date)
occurrences.append(occurrence)
end_date = occurrence - self.min_time_delta()
return occurrences
def last_n_occurrences(self, n, dt=None):
end_date = dt or date_now()
occurrences = []
for i in range(0, n):
occurrence = self.last_natural_occurrence(dt=end_date)
occurrences.append(occurrence)
end_date = occurrence - self.min_time_delta()
return occurrences
def next_n_occurrences(self, n, dt=None):
start_date = dt or date_now()
occurrences = []
for i in range(0, n):
occurrence = self.next_natural_occurrence(dt=start_date)
occurrences.append(occurrence)
start_date = occurrence + self.min_time_delta()
return occurrences
def next_n_occurrences(self, n, dt=None):
start_date = dt or date_now()
occurrences = []
for i in range(0, n):
occurrence = self.next_natural_occurrence(dt=start_date)
occurrences.append(occurrence)
start_date = occurrence + self.min_time_delta()
return occurrences
def create_backup_plan(self, **kwargs):
try:
plan = BackupPlan()
plan.created_date = date_now()
plan.description = get_validate_arg(kwargs, "description",
expected_type=(str, unicode),
required=False)
plan.strategy = get_validate_arg(kwargs, "strategy",
expected_type=BackupStrategy)
plan.schedule = get_validate_arg(kwargs, "schedule",
expected_type=AbstractSchedule)
plan.source = get_validate_arg(kwargs, "source",
expected_type=BackupSource)
plan.target = get_validate_arg(kwargs, "target",
expected_type=BackupTarget)
plan.retention_policy = get_validate_arg(kwargs, "retention_policy",
expected_type=
RetentionPolicy,
required=False)
plan.priority = get_validate_arg(kwargs, "priority",
expected_type=(int, long,
float, complex),
required=False)
plan.secondary_targets = get_validate_arg(kwargs,
"secondary_targets",
expected_type=list,
required=False)
# tags
plan.tags = get_validate_arg(kwargs, "tags", expected_type=dict,
required=False)
plan_doc = plan.to_document()
get_mbs().plan_collection.save_document(plan_doc)
# set the backup plan id from the saved doc
plan.id = plan_doc["_id"]
self.info("Saved backup plan \n%s" % plan)
# process plan to set next occurrence
self._scheduler._process_plan(plan)
return plan
except Exception, e:
args_str = dict_to_str(kwargs)
msg = ("Failed to create plan. Args:\n %s" % args_str)
logger.error(msg)
logger.error(traceback.format_exc())
raise CreatePlanError(msg=msg, cause=e)
def _notify_on_past_due_scheduled_backups(self):
"""
Send notifications for jobs that has been scheduled for a period
longer than min(half the frequency, 5 hours) of its plan.
If backup does not have a plan (i.e. one off)
then it will check after 60 seconds.
"""
# query for backups whose scheduled date is before current date minus
# than max starvation time
where = (
"(Math.min(%s, (this.plan.schedule.frequencyInSeconds / 2) * 1000) + "
"this.createdDate.getTime()) < new Date().getTime()" %
(MAX_BACKUP_WAIT_TIME * 1000))
one_off_starve_date = date_minus_seconds(date_now(),
ONE_OFF_BACKUP_MAX_WAIT_TIME)
q = {
"state":
STATE_SCHEDULED,
"$or": [
# backups with plans starving query
{
"$and": [{
"plan": {
"$exists": True
}
}, {
"$where": where
}]
},
# One off backups (no plan) starving query
{
"$and": [{
"plan": {
"$exists": False
}
}, {
"createdDate": {
"$lt": one_off_starve_date
}
}]
}
]
}
starving_backups = get_mbs().backup_collection.find(q)
if starving_backups:
msg = ("You have %s scheduled backups that has past the maximum "
"waiting time (%s seconds)." %
(len(starving_backups), MAX_BACKUP_WAIT_TIME))
self.info(msg)
self.info("Sending a notification...")
sbj = "Past due scheduled backups"
get_mbs().send_notification(sbj, msg)
def state_change_log_entry(state, message=None):
log_entry = EventLogEntry()
log_entry.event_type = EVENT_TYPE_INFO
log_entry.name = EVENT_STATE_CHANGE
log_entry.date = date_now()
log_entry.state = state
log_entry.message = message
return log_entry
def _process_failed_backup(self, backup):
"""
:param backup:
:return:
"""
logger.info("BackupScheduler: processing failed backup '%s' ..." % backup.id)
if backup.next_retry_date < date_now():
# RESCHEDULE !!!
self._backup_system.reschedule_backup(backup)
def worker_finished(self, worker, state, message=None):
# set end date
worker.task.end_date = date_now()
# decrease worker count and update state
self._worker_count -= 1
worker.task.state = state
self._task_collection.update_task(worker.task,
properties=["state", "endDate"],
event_name=EVENT_STATE_CHANGE, message=message)
def remove_plan(self, plan_id):
plan = get_mbs().plan_collection.get_by_id(plan_id)
if plan:
plan.deleted_date = date_now()
logger.info("Adding plan '%s' to deleted plans" % plan_id)
get_mbs().deleted_plan_collection.save_document(plan.to_document())
logger.info("Removing plan '%s' from plans" % plan_id)
get_mbs().plan_collection.remove_by_id(plan_id)
else:
logger.info("No such plan '%s'" % plan_id)
def worker_finished(self, state, message=None):
# set end date
self._task.end_date = date_now()
self._task.state = state
self.get_task_collection().update_task(
self._task, properties=["state", "endDate", "nextRetryDate", "finalRetryDate", "cleanedUp"],
event_name=EVENT_STATE_CHANGE, message=message)
trigger_task_finished_event(self._task, state)
def schedule_backup(self, **kwargs):
try:
backup = Backup()
backup.created_date = date_now()
backup.strategy = get_validate_arg(kwargs, "strategy",
expected_type=BackupStrategy)
backup.source = get_validate_arg(kwargs, "source", BackupSource)
backup.target = get_validate_arg(kwargs, "target", BackupTarget)
backup.priority = get_validate_arg(kwargs, "priority",
expected_type=(int, long,
float, complex),
required=False)
backup.plan_occurrence = \
get_validate_arg(kwargs, "plan_occurrence",
expected_type=datetime,
required=False)
backup.plan = get_validate_arg(kwargs, "plan",
expected_type=BackupPlan,
required=False)
backup.secondary_targets = get_validate_arg(kwargs,
"secondary_targets",
expected_type=list,
required=False)
backup.change_state(State.SCHEDULED)
# set tags
tags = get_validate_arg(kwargs, "tags", expected_type=dict,
required=False)
backup.tags = tags
bc = get_mbs().backup_collection
try:
# resolve tags
self._resolve_task_tags(backup)
except Exception, ex:
self._task_failed_to_schedule(backup, bc, ex)
self.set_custom_backup_props(backup)
backup_doc = backup.to_document()
get_mbs().backup_collection.save_document(backup_doc)
# set the backup id from the saved doc
backup.id = backup_doc["_id"]
self.info("Saved backup \n%s" % backup)
if backup.state == State.FAILED:
trigger_task_finished_event(backup, State.FAILED)
return backup
def last_natural_occurrence(self, dt=None):
""" NOTE: cron is a minute level resolution. round up in the case of
seconds/microseconds
"""
dt = date_now() if dt is None else dt
if dt.second > 0 or dt.microsecond > 0:
dt = dt.replace(second=0, microsecond=0) + timedelta(minutes=1)
if self._is_occurrence(dt):
return dt
return croniter(self._expression, dt).get_prev(datetime)
def worker_finished(self, worker, state, message=None):
# set end date
worker.task.end_date = date_now()
# decrease worker count and update state
self._worker_count -= 1
worker.task.state = state
self._task_collection.update_task(worker.task,
properties=["state", "endDate"],
event_name=EVENT_STATE_CHANGE,
message=message)
def _process_failed_backup(self, backup):
"""
:param backup:
:return:
"""
logger.info("BackupScheduler: processing failed backup '%s' ..." %
backup.id)
if backup.next_retry_date < date_now():
# RESCHEDULE !!!
self._backup_system.reschedule_backup(backup)
def max_acceptable_lag(self, dt=None):
dt = date_now() if dt is None else dt
if self._is_occurrence(dt):
# we are concerned with the period leading up to dt
return self._max_acceptable_lag_for_period(
dt - self.last_natural_occurrence(dt - timedelta(minutes=1)))
# otherwise we are concerned with the period leading up to the next
# occurrence
return self._max_acceptable_lag_for_period(
self.next_natural_occurrence(dt) -
self.last_natural_occurrence(dt))
def get_download_url(container, file_path):
temp_key = random_temp_shared_key()
storage_url = "https://%s/%s" % (container.conn.connection_args[0],
container.conn.connection_args[2])
set_account_temp_url_key(storage_url, container.conn.token, temp_key)
expire_date = date_plus_seconds(date_now(), 300)
return get_temp_url(container.name, "GET", storage_url, temp_key,
file_path, expire_date)
def state_change_log_entry(state, message=None):
log_entry = EventLogEntry()
log_entry.event_type = EventType.INFO
log_entry.name = EVENT_STATE_CHANGE
log_entry.date = date_now()
log_entry.state = state
log_entry.message = message
return log_entry
def get_download_url(container, file_path):
temp_key = random_temp_shared_key()
storage_url = "https://%s/%s" % (container.conn.connection_args[0],
container.conn.connection_args[2])
set_account_temp_url_key(storage_url, container.conn.token, temp_key)
expire_date = date_plus_seconds(date_now(), 300)
return get_temp_url(container.name, "GET", storage_url, temp_key,
file_path, expire_date)
def delete_backup(self, backup_id):
"""
Deletes the specified backup. Deleting here means expiring
"""
backup = get_mbs().backup_collection.get_by_id(backup_id)
if (backup and backup.target_reference
and not backup.target_reference.expired_date):
expire_backup(backup, date_now())
return True
return False
def natural_occurrences_between(self, start_dt, end_dt=None):
super(CronSchedule, self).natural_occurrences_between(start_dt, end_dt)
end_dt = date_now() if end_dt is None else end_dt
occurrences = []
if self._is_occurrence(start_dt):
occurrences.append(start_dt)
iter_ = croniter(self._expression, start_dt)
occurrences.append(iter_.get_next(datetime))
while occurrences[-1] < end_dt:
occurrences.append(iter_.get_next(datetime))
return occurrences[:-1]
def _do_monitor_activity(self):
self._balancer_active_during_monitor = None
self._stop_balancer_monitor_request = None
while not (self._stop_balancer_monitor_request or
self._balancer_active_during_monitor):
self._balancer_active_during_monitor = self.is_balancer_active()
if self._balancer_active_during_monitor:
logger.info("Balancer activity monitor for '%s' detected balancer was active at '%s'" %
(self, date_now()))
time.sleep(1)
def _check_audit(self):
# TODO Properly run auditors as needed
#
if not self._audit_next_occurrence:
self._audit_next_occurrence = self._get_audit_next_occurrence()
return
if date_now() >= self._audit_next_occurrence():
self.info("Running auditor...")
self.global_auditor.generate_yesterday_audit_reports()
self._audit_next_occurrence = self._get_audit_next_occurrence()
def remove_plan(self, plan_id):
plan = get_mbs().plan_collection.get_by_id(plan_id)
if plan:
plan.deleted_date = date_now()
logger.info("Adding plan '%s' to deleted plans" % plan_id)
get_mbs().deleted_plan_collection.save_document(plan.to_document())
logger.info("Removing plan '%s' from plans" % plan_id)
get_mbs().plan_collection.remove_by_id(plan_id)
return True
else:
logger.info("No such plan '%s'" % plan_id)
return False
def run(self):
task = self._task
try:
# increase # of tries
task.try_count += 1
logger.info("Running %s '%s' (try # %s) (worker PID '%s')..." %
(task.type_name, task.id, task.try_count, os.getpid()))
logger.info(str(task))
# set start date
task.start_date = date_now()
task.worker_info = self.get_worker_info()
# set queue_latency_in_minutes if its not already set
if not task.queue_latency_in_minutes:
latency = self._calculate_queue_latency(task)
task.queue_latency_in_minutes = latency
# clear end date
task.end_date = None
# UPDATE!
self.get_task_collection().update_task(task,
properties=[
"tryCount", "startDate",
"endDate",
"queueLatencyInMinutes",
"workerInfo"
])
# run the task
task.execute()
# cleanup temp workspace
task.cleanup()
# success!
self.worker_success()
logger.info("%s '%s' completed successfully" %
(task.type_name, task.id))
except Exception, e:
# fail
trace = traceback.format_exc()
logger.error("%s failed. Cause %s. \nTrace: %s" %
(task.type_name, e, trace))
self.worker_fail(exception=e, trace=trace)
def _process_failed_backups(self):
"""
Reschedule failed backups that failed and are retriable
"""
q = {
"state": State.FAILED,
"nextRetryDate": {
"$lt": date_now()
}
}
for backup in get_mbs().backup_collection.find(q):
self._process_failed_backup(backup)
def run(self):
task = self.task
try:
# increase # of tries
task.try_count += 1
self.info("Running task %s (try # %s)" %
(task._id, task.try_count))
# set start date
task.start_date = date_now()
# set queue_latency_in_minutes if its not already set
if not task.queue_latency_in_minutes:
latency = self._calculate_queue_latency(task)
task.queue_latency_in_minutes = latency
# clear end date
task.end_date = None
# set the workspace
workspace_dir = self._get_task_workspace_dir(task)
task.workspace = workspace_dir
# ensure backup workspace
ensure_dir(task.workspace)
# UPDATE!
self._processor._task_collection.update_task(task,
properties=["tryCount", "startDate",
"endDate", "workspace",
"queueLatencyInMinutes"])
# run the task
task.execute()
# cleanup temp workspace
task.cleanup()
# success!
self._processor.worker_success(self)
self.info("Task '%s' completed successfully" % task.id)
except Exception, e:
# fail
trace = traceback.format_exc()
self.error("Task failed. Cause %s. \nTrace: %s" % (e, trace))
self._processor.worker_fail(self, exception=e, trace=trace)
def _do_monitor_activity(self):
self._balancer_active_during_monitor = None
self._stop_balancer_monitor_request = None
# TODO remove old monitoring technique if the new one is good enough
# new technique ! may be good enough
self._current_balaner_run_date_str = self.get_balaner_latest_run_date_str()
while not (self._stop_balancer_monitor_request or
self._balancer_active_during_monitor):
self._balancer_active_during_monitor = self.is_balancer_active()
if self._balancer_active_during_monitor:
logger.info("Balancer activity monitor for '%s' detected balancer was active at '%s'" %
(self, date_now()))
time.sleep(1)
def robustified_delete_backup(backup):
"""
deletes the backup targets
"""
# do some validation,
target_ref = backup.target_reference
if backup.state == State.SUCCEEDED and not target_ref:
raise BackupSweepError("Cannot delete backup '%s'. "
"Backup never uploaded" % backup.id)
logger.info("Deleting target references for backup '%s'." % backup.id)
logger.info("Deleting primary target reference for backup '%s'." %
backup.id)
# target ref can be None for CANCELED backups
if target_ref:
do_delete_target_ref(backup, backup.target, target_ref)
# delete log file
if backup.log_target_reference:
logger.info("Deleting log target reference for backup '%s'." %
backup.id)
do_delete_target_ref(backup, backup.target,
backup.log_target_reference)
if backup.secondary_target_references:
logger.info("Deleting secondary target references for backup '%s'." %
backup.id)
sec_targets = backup.secondary_targets
sec_target_refs = backup.secondary_target_references
for (sec_target, sec_tgt_ref) in zip(sec_targets, sec_target_refs):
logger.info("Deleting secondary target reference %s for backup "
"'%s'." % (sec_tgt_ref, backup.id))
do_delete_target_ref(backup, sec_target, sec_tgt_ref)
# set deleted date
backup.deleted_date = date_now()
update_props = ["deletedDate", "targetReference",
"secondaryTargetReferences"]
persistence.update_backup(backup, properties=update_props,
event_name="DELETING",
message="Deleting target references")
logger.info("Backup %s target references deleted successfully!" %
backup.id)
def log_event(self, event_type=EventType.INFO, name=None, message=None,
details=None, error_code=None):
logs = self.logs
log_entry = EventLogEntry()
log_entry.event_type = event_type
log_entry.name = name
log_entry.date = date_now()
log_entry.state = self.state
log_entry.message = message
log_entry.details = details
log_entry.error_code = error_code
logs.append(log_entry)
self.logs = logs
return log_entry
def natural_occurrences_between(self, start_dt, end_dt=None):
super(Schedule, self).natural_occurrences_between(start_dt, end_dt)
end_dt = date_now() if end_dt is None else end_dt
occurrences = []
last_occurrence = self.last_natural_occurrence(start_dt)
delta = timedelta(seconds=self.frequency_in_seconds)
while last_occurrence < end_dt:
if last_occurrence >= start_dt:
occurrences.append(last_occurrence)
last_occurrence = last_occurrence + delta
return occurrences
def natural_occurrences_between(self, start_dt, end_dt=None):
""" Get the scheduled occurrences between two dates
NOTE: The occurrences returned are not inclusive of end_dt.
args:
start_dt - the starting datetime for the period over which all
occurrences of a scheduled action should be returned
end_dt - the ending datetime of the period (if None, end_dt
will default to the current time)
"""
if end_dt is None:
end_dt = date_now()
if end_dt <= start_dt:
raise Exception('end_dt must be greater than start_dt')
