diff --git a/SAS/TMSS/backend/services/scheduling/lib/constraints.py b/SAS/TMSS/backend/services/scheduling/lib/constraints.py index 2857b7193d07c5486d207614623c0e53f55dcd11..32cde979c0c8773e0305ca7ff60f73c47b73d847 100644 --- a/SAS/TMSS/backend/services/scheduling/lib/constraints.py +++ b/SAS/TMSS/backend/services/scheduling/lib/constraints.py @@ -1779,7 +1779,20 @@ def get_earliest_possible_start_time_taking_used_stations_into_account(schedulin latest_blocking_stop_time = max([unit.on_sky_stop_time for unit in blocking_units]) from .dynamic_scheduling import DEFAULT_INTER_OBSERVATION_GAP advanced_lower_bound = latest_blocking_stop_time + DEFAULT_INTER_OBSERVATION_GAP - return get_earliest_possible_start_time_taking_used_stations_into_account(scheduling_unit, advanced_lower_bound, upper_bound, gridder, raise_if_interruped) + if advanced_lower_bound < upper_bound: + logger.debug("get_earliest_possible_start_time_taking_used_stations_into_account: SUB id=%s earliest_possible_start_time='%s' is blocked by units %s. Advancing window from lower_bound='%s' to new lower_bound='%s', upper_bound='%s'", + scheduling_unit.id, earliest_possible_start_time, ','.join(str(u.id) for u in blocking_units), lower_bound, advanced_lower_bound, upper_bound) + + advanced_earliest_possible_start_time = get_earliest_possible_start_time_taking_used_stations_into_account(scheduling_unit, advanced_lower_bound, upper_bound, gridder, raise_if_interruped) + + if advanced_earliest_possible_start_time is not None: + logger.debug("get_earliest_possible_start_time_taking_used_stations_into_account: SUB id=%s advanced_earliest_possible_start_time='%s' lower_bound='%s', upper_bound='%s'", + scheduling_unit.id, advanced_earliest_possible_start_time, advanced_lower_bound, upper_bound) + return advanced_earliest_possible_start_time + + logger.info("get_earliest_possible_start_time_taking_used_stations_into_account: SUB id=%s is blocked by units %s at earliest_possible_start_time='%s'", + scheduling_unit.id, ','.join(str(u.id) for u in blocking_units), earliest_possible_start_time) + return None return earliest_possible_start_time @@ -1969,7 +1982,7 @@ def get_weighted_start_time(scheduling_unit: models.SchedulingUnitBlueprint, low logger.debug("get_weighted_start_time: SUB id=%s returning earliest='%s' - window=['%s', '%s']", scheduling_unit.id, earliest_possible_start_time, lower_bound, upper_bound) return earliest_possible_start_time - logger.warning("get_weighted_start_time: SUB id=%s could not compute weighted_start_time - window=['%s', '%s']", scheduling_unit.id, lower_bound, upper_bound) + logger.debug("get_weighted_start_time: SUB id=%s could not compute weighted_start_time - window=['%s', '%s']", scheduling_unit.id, lower_bound, upper_bound) return None @@ -1993,30 +2006,33 @@ def compute_individual_and_weighted_scores(scheduling_units: [models.SchedulingU logger.info("compute_individual_and_weighted_scores: scored unit [%d/%d] %.1f%% %s", i+1, len(scheduling_units), 100.0 * (i+1) / len(scheduling_units), scored_su) else: - logger.warning("compute_individual_and_weighted_scores: could not determine scores/start_time for unit [%d/%d] %.1f%% id=%d", + logger.info("compute_individual_and_weighted_scores: could not determine scores/start_time for unit [%d/%d] %.1f%% id=%d", i+1, len(scheduling_units), 100.0 * (i+1) / len(scheduling_units), su.id) except Exception as e: logger.exception(e) - # create/get a weight per unique score_name, caching it in a dict, thus reducing the number of be calls. - weight_for_score_name = {} - for score_name in sorted(list(score_names)): - weight_factor, created = models.SchedulingConstraintsWeightFactor.objects.get_or_create(constraint_name=score_name, - defaults={'weight': 1.0}) - weight_for_score_name[score_name] = weight_factor.weight - - logger.info('compute_individual_and_weighted_scores: weights: %s' , ' '.join(['%s=%.4f' % (score_name, weight_for_score_name[score_name]) for score_name in sorted(list(score_names))])) - - # do the actual weighting - for i, scored_su in enumerate(scored_scheduling_units): - # compute weighted total score - weighted_score = 0.0 - for score_key, score_value in scored_su.scores.items(): - weight = weight_for_score_name[score_key] - weighted_score += weight * score_value - scored_su.weighted_score = weighted_score / float(len(scored_su.scores)) - logger.info("compute_individual_and_weighted_scores: weighted scores for unit [%d/%d] %.1f%% %s", i+1, len(scored_scheduling_units), 100.0 * (i + 1) / len(scored_scheduling_units), scored_su) + if scored_scheduling_units: + logger.info('compute_individual_and_weighted_scores: scored %d/%d units', len(scored_scheduling_units), len(scheduling_units)) + + # create/get a weight per unique score_name, caching it in a dict, thus reducing the number of be calls. + weight_for_score_name = {} + for score_name in sorted(list(score_names)): + weight_factor, created = models.SchedulingConstraintsWeightFactor.objects.get_or_create(constraint_name=score_name, + defaults={'weight': 1.0}) + weight_for_score_name[score_name] = weight_factor.weight + + logger.info('compute_individual_and_weighted_scores: applying weights: %s' , ' '.join(['%s=%.4f' % (score_name, weight_for_score_name[score_name]) for score_name in sorted(list(score_names))])) + + # do the actual weighting + for i, scored_su in enumerate(scored_scheduling_units): + # compute weighted total score + weighted_score = 0.0 + for score_key, score_value in scored_su.scores.items(): + weight = weight_for_score_name[score_key] + weighted_score += weight * score_value + scored_su.weighted_score = weighted_score / float(len(scored_su.scores)) + logger.info("compute_individual_and_weighted_scores: weighted scores for unit [%d/%d] %.1f%% %s", i+1, len(scored_scheduling_units), 100.0 * (i + 1) / len(scored_scheduling_units), scored_su) return scored_scheduling_units diff --git a/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py b/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py index e3aa288490f4817a0ee5627fe597974924be1da7..5520e56f1100c6f9962d76bb2ce4d375cee8d7ec 100644 --- a/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py +++ b/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py @@ -554,6 +554,7 @@ class Scheduler: # scanning from now+DEFAULT_NEXT_STARTTIME_GAP may include/overlap with already running and/or scheduled observations. That's ok. There are rules to handle the precedence who wins. lower_bound_start_time = round_to_second_precision(max(datetime.utcnow() + DEFAULT_NEXT_STARTTIME_GAP, min([su.earliest_possible_cycle_start_time for su in candidate_units]))) + lower_bound_start_time = datetime(2023, 10, 6, 15) # upper bound of search window is at least a 24h later, or up unit latest cycle end time upper_bound_stop_time = round_to_second_precision(max(lower_bound_start_time + timedelta(days=1), @@ -710,10 +711,12 @@ class Scheduler: if (upper_bound_stop_time - lower_bound_start_time) <= 2*DEFAULT_INTER_OBSERVATION_GAP + timedelta(minutes=1): continue # gap is too small - logger.info("place_B_priority_units_in_gaps: evaluating %s B-queue units in %d[min]-wide gap ['%s', '%s') next to unit id=%s", + logger.info("place_B_priority_units_in_gaps: evaluating %s B-queue units in %d[min]-wide gap ['%s', '%s') %s unit id=%s", schedulable_units_queue_B.count(), (upper_bound_stop_time-lower_bound_start_time).total_seconds()/60, - lower_bound_start_time, upper_bound_stop_time, scheduling_unit.id) + lower_bound_start_time, upper_bound_stop_time, + "before" if gap[1] <= scheduling_unit.scheduled_start_time else "after", + scheduling_unit.id) best_B_candidate_for_gap = self.find_best_next_schedulable_unit(schedulable_units_queue_B, lower_bound_start_time=lower_bound_start_time, upper_bound_stop_time=upper_bound_stop_time) if best_B_candidate_for_gap is not None and best_B_candidate_for_gap.scheduling_unit is not None: