diff --git a/SAS/TMSS/backend/services/scheduling/lib/constraints.py b/SAS/TMSS/backend/services/scheduling/lib/constraints.py index d283522cf1cbf215ab7db79d4998eb708f0d3a57..5a65a637b02c19b97d9017f2f8176fea7ed9b995 100644 --- a/SAS/TMSS/backend/services/scheduling/lib/constraints.py +++ b/SAS/TMSS/backend/services/scheduling/lib/constraints.py @@ -379,7 +379,7 @@ def sort_scheduling_units_scored_by_constraints(scheduling_units: [models.Schedu x.scheduling_unit.created_at), reverse=True) -def can_run_within_timewindow(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime, gridder: Gridder=None) -> bool: +def can_run_within_timewindow(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime, gridder: Gridder=None, raise_if_interruped: Callable=noop) -> bool: '''determine if the given scheduling_unit can run withing the given timewindow evaluating all constraints from the "constraints" version 1 template :param raise_if_interruped: a callable function which raises under an externally set condition (an 'interrupt' flag was set). This function is/can_be used to interrupt a long-running scheduling call to do an early exit and start a new scheduling call. Default used function is noop (no-operation), thus no interruptable behaviour. ''' @@ -387,7 +387,7 @@ def can_run_within_timewindow(scheduling_unit: models.SchedulingUnitBlueprint, l gridder = Gridder() # Seek the earliest_possible_start_time. If existing and within window, then the unit can run within this window - earliest_possible_start_time = get_earliest_possible_start_time(scheduling_unit, lower_bound, upper_bound, gridder) + earliest_possible_start_time = get_earliest_possible_start_time(scheduling_unit, lower_bound, upper_bound, gridder, raise_if_interruped) if earliest_possible_start_time is not None: earliest_possible_stop_time = earliest_possible_start_time + scheduling_unit.specified_main_observation_duration if earliest_possible_start_time >= lower_bound and earliest_possible_stop_time <= upper_bound: @@ -994,7 +994,7 @@ def evaluate_sky_min_distance_constraint(scheduling_unit: models.SchedulingUnitB return result @lru_cache(maxsize=10000) -def get_earliest_possible_start_time_for_sky_min_elevation(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=Gridder()) -> datetime: +def get_earliest_possible_start_time_for_sky_min_elevation(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=Gridder(), raise_if_interruped: Callable=noop) -> datetime: # do expensive search from lower_bound until 24 hours later with small steps # (sky constrains are (almost) cyclic over 24 hours). # first occurrence where min_elevation constraint is met is taken as rough estimate of earliest_possible_start_time @@ -1004,6 +1004,8 @@ def get_earliest_possible_start_time_for_sky_min_elevation(scheduling_unit: mode upper_bound = lower_bound + timedelta(hours=24) upper_bound = max(lower_bound, upper_bound) while possible_start_time < upper_bound: + raise_if_interruped() + result = evaluate_sky_min_elevation_constraint(scheduling_unit, possible_start_time, gridder=gridder) logger.debug('get_earliest_possible_start_time_for_sky_min_elevation %s', result) @@ -1031,7 +1033,7 @@ def get_earliest_possible_start_time_for_sky_min_elevation(scheduling_unit: mode return None -def get_earliest_possible_start_time_for_sky_transit_offset(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None) -> datetime: +def get_earliest_possible_start_time_for_sky_transit_offset(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None, raise_if_interruped: Callable=noop) -> datetime: # compute the transit time, and thus the optimal_start_time and earliest_possible_start_time if gridder is None: gridder = Gridder() @@ -1044,6 +1046,8 @@ def get_earliest_possible_start_time_for_sky_transit_offset(scheduling_unit: mod allow_quick_jump = True # see below, we can quick jump once, but use monotonous increments so ensure an exit of the while loop. while possible_start_time < upper_bound: + raise_if_interruped() + gridded_possible_start_time = gridder.grid_time(possible_start_time) result = evaluate_sky_transit_constraint(scheduling_unit, gridded_possible_start_time, gridder=gridder, which='next') logger.debug('get_earliest_possible_start_time_for_sky_transit_offset %s', result) @@ -1068,7 +1072,7 @@ def get_earliest_possible_start_time_for_sky_transit_offset(scheduling_unit: mod return None @lru_cache(maxsize=10000) -def get_earliest_possible_start_time_for_sky_min_distance(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None) -> datetime: +def get_earliest_possible_start_time_for_sky_min_distance(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None, raise_if_interruped: Callable=noop) -> datetime: # do expensive search from lower_bound until 24 hours later with small steps # (sky constrains are (almost) cyclic over 24 hours). # first occurrence where min_distance constraint is met is taken as rough estimate of earliest_possible_start_time @@ -1081,6 +1085,8 @@ def get_earliest_possible_start_time_for_sky_min_distance(scheduling_unit: model upper_bound = max(lower_bound, upper_bound) while possible_start_time < upper_bound: + raise_if_interruped() + result = evaluate_sky_min_distance_constraint(scheduling_unit, possible_start_time, gridder=gridder) logger.debug('get_earliest_possible_start_time_for_sky_min_distance %s', result) @@ -1247,7 +1253,7 @@ def evaluate_daily_constraints(scheduling_unit: models.SchedulingUnitBlueprint, return result @lru_cache(maxsize=10000) -def get_earliest_possible_start_time_for_daily_constraints(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None) -> datetime: +def get_earliest_possible_start_time_for_daily_constraints(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None, raise_if_interruped: Callable=noop) -> datetime: # search from lower_bound until 24 hours later with 6 hour steps # (daily constrains are (almost) cyclic over 24 hours) if gridder is None: @@ -1255,6 +1261,8 @@ def get_earliest_possible_start_time_for_daily_constraints(scheduling_unit: mode gridded_lower_bound = gridder.grid_time(lower_bound) possible_start_time = gridded_lower_bound while possible_start_time < lower_bound+timedelta(hours=24): + raise_if_interruped() + result = evaluate_daily_constraints(scheduling_unit, possible_start_time, gridder=gridder) logger.debug('get_earliest_possible_start_time_for_daily_constraints %s', result) @@ -1267,9 +1275,13 @@ def get_earliest_possible_start_time_for_daily_constraints(scheduling_unit: mode continue if result.is_constraint_met: + logger.debug('get_earliest_possible_start_time_for_daily_constraints(id=%s, lb=%s, up=%s) result=%s', scheduling_unit.id, lower_bound, upper_bound, result) if result.earliest_possible_start_time >= lower_bound: if upper_bound is None or result.earliest_possible_start_time < upper_bound: return result.earliest_possible_start_time + else: + # do not advance past upper_bound + return None # advance with a grid step, and evaluate again possible_start_time += gridder.as_timedelta() @@ -1277,7 +1289,7 @@ def get_earliest_possible_start_time_for_daily_constraints(scheduling_unit: mode return None -def get_earliest_possible_start_time_for_time_constraints(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None) -> datetime: +def get_earliest_possible_start_time_for_time_constraints(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None, raise_if_interruped: Callable=noop) -> datetime: ''' ''' constraints = scheduling_unit.scheduling_constraints_doc @@ -1354,7 +1366,7 @@ def get_at_constraint_timestamp(scheduling_unit: models.SchedulingUnitBlueprint) return at return None -def get_earliest_possible_start_time(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None) -> datetime: +def get_earliest_possible_start_time(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None, raise_if_interruped: Callable=noop) -> datetime: ''' ''' _method_start_timestamp = datetime.utcnow() @@ -1378,9 +1390,11 @@ def get_earliest_possible_start_time(scheduling_unit: models.SchedulingUnitBluep get_earliest_possible_start_time_for_sky_transit_offset, get_earliest_possible_start_time_for_sky_min_distance): try: - earliest_possible_start_time = get_earliest_possible_start_time_method(scheduling_unit, lower_bound, upper_bound, gridder) + earliest_possible_start_time = get_earliest_possible_start_time_method(scheduling_unit, lower_bound, upper_bound, gridder, raise_if_interruped) if earliest_possible_start_time is not None: earliest_possible_start_times.add(earliest_possible_start_time) + except SchedulerInterruptedException: + raise except Exception as e: logger.exception(e) @@ -1580,7 +1594,7 @@ def compute_scheduling_unit_scores(scheduling_unit: models.SchedulingUnitBluepri # return the actual (not the gridded) weighted_start_time start_time=weighted_start_time) -def get_min_earliest_possible_start_time(scheduling_units: [models.SchedulingUnitBlueprint], lower_bound: datetime, upper_bound: datetime=None, raise_if_interruped: Callable=noop, gridder: Gridder=None) -> datetime: +def get_min_earliest_possible_start_time(scheduling_units: [models.SchedulingUnitBlueprint], lower_bound: datetime, upper_bound: datetime=None, gridder: Gridder=None, raise_if_interruped: Callable=noop) -> datetime: '''deterimine the earliest possible starttime over all given scheduling units, taking into account all their constraints :param raise_if_interruped: a callable function which raises under an externally set condition (an 'interrupt' flag was set). This function is/can_be used to interrupt a long-running scheduling call to do an early exit and start a new scheduling call. Default used function is noop (no-operation), thus no interruptable behaviour. ''' @@ -1591,7 +1605,7 @@ def get_min_earliest_possible_start_time(scheduling_units: [models.SchedulingUni raise_if_interruped() if scheduling_unit.scheduling_constraints_template is not None: - earliest_possible_start_time = get_earliest_possible_start_time(scheduling_unit, lower_bound, upper_bound, gridder) + earliest_possible_start_time = get_earliest_possible_start_time(scheduling_unit, lower_bound, upper_bound, gridder, raise_if_interruped) if earliest_possible_start_time is not None: if min_earliest_possible_start_time is None or earliest_possible_start_time < min_earliest_possible_start_time: min_earliest_possible_start_time = earliest_possible_start_time @@ -1622,8 +1636,9 @@ def get_missing_stations_for_scheduling_unit(scheduling_unit: models.SchedulingU return sorted((list(missing_stations))) -def determine_unschedulable_reason_and_mark_unschedulable_if_needed(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime, gridder: Gridder) -> models.SchedulingUnitBlueprint: +def determine_unschedulable_reason_and_mark_unschedulable_if_needed(scheduling_unit: models.SchedulingUnitBlueprint, lower_bound: datetime, upper_bound: datetime, gridder: Gridder, raise_if_interruped: Callable=noop) -> models.SchedulingUnitBlueprint: try: + logger.debug("determine_unschedulable_reason_and_mark_unschedulable_if_needed: scheduling_unit id=%s", scheduling_unit.id) if not can_run_within_station_reservations(scheduling_unit): missing_stations = get_missing_stations_for_scheduling_unit(scheduling_unit) msg = "Stations %s are reserved" % (missing_stations, ) @@ -1632,7 +1647,7 @@ def determine_unschedulable_reason_and_mark_unschedulable_if_needed(scheduling_u if gridder is None: gridder = Gridder() - if not can_run_within_timewindow(scheduling_unit, lower_bound, upper_bound, gridder): + if not can_run_within_timewindow(scheduling_unit, lower_bound, upper_bound, gridder, raise_if_interruped): # nope, can't run, so check each type of constraint unmet_constraints = [] @@ -1662,23 +1677,23 @@ def determine_unschedulable_reason_and_mark_unschedulable_if_needed(scheduling_u if 'sky' in scheduling_unit.scheduling_constraints_doc: if 'min_elevation' in scheduling_unit.scheduling_constraints_doc['sky']: - if get_earliest_possible_start_time_for_sky_min_elevation(scheduling_unit, lower_bound, upper_bound, gridder) is None: + if get_earliest_possible_start_time_for_sky_min_elevation(scheduling_unit, lower_bound, upper_bound, gridder, raise_if_interruped) is None: unmet_constraints.append("sky min_elevation") if 'transit_offset' in scheduling_unit.scheduling_constraints_doc['sky']: - if get_earliest_possible_start_time_for_sky_transit_offset(scheduling_unit, lower_bound, upper_bound, gridder) is None: + if get_earliest_possible_start_time_for_sky_transit_offset(scheduling_unit, lower_bound, upper_bound, gridder, raise_if_interruped) is None: unmet_constraints.append("sky transit_offset") if 'min_distance' in scheduling_unit.scheduling_constraints_doc['sky']: - if get_earliest_possible_start_time_for_sky_min_distance(scheduling_unit, lower_bound, upper_bound, gridder) is None: + if get_earliest_possible_start_time_for_sky_min_distance(scheduling_unit, lower_bound, upper_bound, gridder, raise_if_interruped) is None: unmet_constraints.append("sky min_distance") if 'time' in scheduling_unit.scheduling_constraints_doc: - if get_earliest_possible_start_time_for_time_constraints(scheduling_unit, lower_bound, upper_bound, gridder) is None: + if get_earliest_possible_start_time_for_time_constraints(scheduling_unit, lower_bound, upper_bound, gridder, raise_if_interruped) is None: unmet_constraints.append("time") if 'daily' in scheduling_unit.scheduling_constraints_doc: - if get_earliest_possible_start_time_for_daily_constraints(scheduling_unit, lower_bound, upper_bound, gridder) is None: + if get_earliest_possible_start_time_for_daily_constraints(scheduling_unit, lower_bound, upper_bound, gridder, raise_if_interruped) is None: unmet_constraints.append("daily") if unmet_constraints: @@ -1688,6 +1703,8 @@ def determine_unschedulable_reason_and_mark_unschedulable_if_needed(scheduling_u else: mark_independent_subtasks_in_scheduling_unit_blueprint_as_unschedulable(scheduling_unit, "sorry, unknown unschedulable reason.") + except SchedulerInterruptedException: + raise except Exception as e: logger.exception(e) mark_independent_subtasks_in_scheduling_unit_blueprint_as_unschedulable(scheduling_unit, str(e)) diff --git a/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py b/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py index 6c9c7b2eb71b72ed381db5a442d855118e085f26..b363c6c1efbbbb21859ed8ce2e8841c5d42e294e 100644 --- a/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py +++ b/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py @@ -337,7 +337,7 @@ class Scheduler: logger.info("find_best_next_schedulable_unit: units meeting constraints in window ['%s', '%s']: %s", lower_bound_start_time, upper_bound_stop_time, ','.join([str(su.id) for su in sorted(filtered_scheduling_units, key=lambda x: x.id)]) or 'None') if not filtered_scheduling_units: - logger.warning("find_best_next_schedulable_unit: no units meeting constraints in window ['%s', '%s']", lower_bound_start_time, upper_bound_stop_time) + logger.info("find_best_next_schedulable_unit: no units meeting constraints in window ['%s', '%s']", lower_bound_start_time, upper_bound_stop_time) return None # then, check if there is a subset that can only run exclusively in this window and not later. @@ -479,14 +479,14 @@ class Scheduler: # nothing was found, or an error occurred. # it may be that in the mean time some scheduling_units are not (dynamically) schedulable anymore, filter those out. for su in candidate_units: - determine_unschedulable_reason_and_mark_unschedulable_if_needed(su, lower_bound_start_time, upper_bound_stop_time, self.search_gridder) + determine_unschedulable_reason_and_mark_unschedulable_if_needed(su, lower_bound_start_time, upper_bound_stop_time, self.search_gridder, raise_if_interruped=self._raise_if_triggered) # all units are refreshed and either schedulable or unschedulable. # refresh list of schedulable_units to be considered in next round (only schedulable) candidate_units = [su for su in candidate_units if su.status.value==models.SchedulingUnitStatus.Choices.SCHEDULABLE.value] # advance the window - min_earliest_possible_start_time = get_min_earliest_possible_start_time(candidate_units, lower_bound_start_time+timedelta(hours=1), lower_bound_start_time+timedelta(hours=25), self._raise_if_triggered, gridder=self.search_gridder) + min_earliest_possible_start_time = get_min_earliest_possible_start_time(candidate_units, lower_bound_start_time+timedelta(hours=1), lower_bound_start_time+timedelta(hours=25), gridder=self.search_gridder, raise_if_interruped=self._raise_if_triggered) if min_earliest_possible_start_time is None: lower_bound_start_time += timedelta(hours=6) else: @@ -611,7 +611,7 @@ class Scheduler: scheduling_units.remove(placed_B_unit) else: # search again in a later timeslot - min_earliest_possible_start_time = get_min_earliest_possible_start_time(scheduling_units, lower_bound_start_time+timedelta(minutes=60), lower_bound_start_time+timedelta(hours=25), self._raise_if_triggered, gridder=self.search_gridder) + min_earliest_possible_start_time = get_min_earliest_possible_start_time(scheduling_units, lower_bound_start_time+timedelta(minutes=60), lower_bound_start_time+timedelta(hours=25), gridder=self.search_gridder, raise_if_interruped=self._raise_if_triggered) logger.info("lower_bound_start_time='%s', min_earliest_possible_start_time='%s'", lower_bound_start_time, min_earliest_possible_start_time) if min_earliest_possible_start_time is not None and min_earliest_possible_start_time > lower_bound_start_time: lower_bound_start_time = min_earliest_possible_start_time diff --git a/SAS/TMSS/backend/src/tmss/tmssapp/subtasks.py b/SAS/TMSS/backend/src/tmss/tmssapp/subtasks.py index bdcb9bbd4f643987f6be9b7a71ce9275d47663a9..585d835ac9f9969986ad79d6b66b1c7818a22fb5 100644 --- a/SAS/TMSS/backend/src/tmss/tmssapp/subtasks.py +++ b/SAS/TMSS/backend/src/tmss/tmssapp/subtasks.py @@ -1197,6 +1197,7 @@ def mark_independent_subtasks_in_task_blueprint_as_schedulable(task_blueprint: T def mark_subtask_as_unschedulable(subtask: Subtask, reason: str): '''Convenience method: Mark the subtask as unschedulable. Unschedules first if needed.''' with transaction.atomic(): + logger.info("marking subtask id=%s from scheduling_unit_id=%s as unschedulable. reason: %s", subtask.id, subtask.task_blueprint.scheduling_unit_blueprint.id, reason) if subtask.state.value == SubtaskState.Choices.SCHEDULED.value: unschedule_subtask(subtask, post_state=SubtaskState.objects.get(value=SubtaskState.Choices.UNSCHEDULABLE.value)) else: @@ -1218,6 +1219,7 @@ def mark_subtasks_and_successors_as_unschedulable(subtask: Subtask, reason: str) def mark_subtask_as_defined(subtask: Subtask): '''Convenience method: Mark the subtask as defined, making it's task & scheduling_unit schedulable. Unschedules first if needed.''' with transaction.atomic(): + logger.info("marking subtask id=%s from scheduling_unit_id=%s as defined/schedulable.", subtask.id, subtask.task_blueprint.scheduling_unit_blueprint.id) if subtask.state.value == SubtaskState.Choices.SCHEDULED.value: unschedule_subtask(subtask, post_state=SubtaskState.objects.get(value=SubtaskState.Choices.DEFINED.value)) else: