diff --git a/SAS/TMSS/backend/services/scheduling/lib/constraints.py b/SAS/TMSS/backend/services/scheduling/lib/constraints.py
index 147ea15970ca20adfece81da41e275e58c651df1..26c2813a3ea76002cd58ae2822ad4e8eb1610ed1 100644
--- a/SAS/TMSS/backend/services/scheduling/lib/constraints.py
+++ b/SAS/TMSS/backend/services/scheduling/lib/constraints.py
@@ -407,7 +407,10 @@ def filter_scheduling_units_which_can_only_run_in_this_window(scheduling_units:
logger.exception(e)
_method_elapsed = datetime.utcnow() - _method_start_timestamp
- logger.info("filter_scheduling_units_which_can_only_run_in_this_window: filtered %d units of which %s are runnable exclusively in window ['%s', '%s'] (took %.1f[s])", len(scheduling_units), len(runnable_exclusive_in_this_window_scheduling_units), lower_bound, upper_bound, _method_elapsed.total_seconds())
+ if runnable_exclusive_in_this_window_scheduling_units:
+ logger.info("filter_scheduling_units_which_can_only_run_in_this_window: filtered %d units of which %s are runnable exclusively in window ['%s', '%s'] (took %.1f[s])", len(scheduling_units), len(runnable_exclusive_in_this_window_scheduling_units), lower_bound, upper_bound, _method_elapsed.total_seconds())
+ else:
+ logger.info("filter_scheduling_units_which_can_only_run_in_this_window: all %d units can run outside of window ['%s', '%s'] (took %.1f[s])", len(scheduling_units), lower_bound, upper_bound, _method_elapsed.total_seconds())
return runnable_exclusive_in_this_window_scheduling_units
@@ -1862,7 +1865,7 @@ def get_weighted_start_time(scheduling_unit: models.SchedulingUnitBlueprint, low
weighted_start_time = round_to_second_precision(weighted_start_time)
if can_run_at(scheduling_unit, weighted_start_time, gridder):
- logger.info("get_weighted_start_time: SUB id=%s weighted='%s' - weight=%.3f earliest='%s' optimal='%s' latest='%s' - window=['%s', '%s']", scheduling_unit.id, weighted_start_time, density_vs_optimal.weight, earliest_possible_start_time, optimal_start_time, latest_possible_start_time, lower_bound, upper_bound)
+ logger.debug("get_weighted_start_time: SUB id=%s weighted='%s' - weight=%.3f earliest='%s' optimal='%s' latest='%s' - window=['%s', '%s']", scheduling_unit.id, weighted_start_time, density_vs_optimal.weight, earliest_possible_start_time, optimal_start_time, latest_possible_start_time, lower_bound, upper_bound)
return weighted_start_time
logger.info("get_weighted_start_time: SUB id=%s returning earliest='%s' - window=['%s', '%s']", scheduling_unit.id, earliest_possible_start_time, lower_bound, upper_bound)
diff --git a/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py b/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py
index 87c3ffc97acd4ed89ea51caeb5e20cc8543bec9c..e43768f0fe9f0b97f0be030a552f7a0133e3e011 100644
--- a/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py
+++ b/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py
@@ -56,7 +56,7 @@ from datetime import datetime, timedelta, time
from lofar.sas.tmss.tmss.tmssapp import models
from lofar.sas.tmss.tmss.tmssapp.tasks import schedule_independent_subtasks_in_scheduling_unit_blueprint, unschedule_subtasks_in_scheduling_unit_blueprint, mark_independent_subtasks_in_scheduling_unit_blueprint_as_unschedulable, mark_independent_subtasks_in_scheduling_unit_blueprint_as_schedulable, mark_independent_subtasks_in_scheduling_unit_blueprint_as_schedulable, set_scheduling_unit_blueprint_start_times, reschedule_subtasks_in_scheduling_unit_blueprint, get_gaps_to_previous_and_next_observations_in_scheduling_unit
-from lofar.sas.tmss.tmss.tmssapp.subtasks import update_subtasks_start_times_for_scheduling_unit, cancel_subtask, mark_subtasks_and_successors_as_defined, get_gaps_between_scheduled_units_in_window
+from lofar.sas.tmss.tmss.tmssapp.subtasks import update_subtasks_start_times_for_scheduling_unit, cancel_subtask, mark_subtasks_and_successors_as_defined, get_gaps_between_scheduled_units_in_window, get_used_stations_in_timewindow
from lofar.sas.tmss.client.tmssbuslistener import *
from lofar.common.datetimeutils import round_to_second_precision
from threading import Thread, Event
@@ -367,10 +367,19 @@ class Scheduler:
# check gap size: minimal obs duration of 1 minute, plus an inter_observation_gap at both sides
if (_upper_bound - _lower_bound) <= 2 * DEFAULT_INTER_OBSERVATION_GAP + timedelta(minutes=1):
# gap is too small
- logger.debug("find_best_next_schedulable_unit: skipping too small window where nothing fits ['%s', '%s']",_lower_bound, _upper_bound)
+ logger.debug("find_best_next_schedulable_unit: skipping too small %dmin window where nothing fits ['%s', '%s']",
+ (_upper_bound - _lower_bound).total_seconds() / 60.0,
+ _lower_bound, _upper_bound)
return None
- logger.info("find_best_next_schedulable_unit: evaluating constraints for units in window ['%s', '%s']: %s",
+ if len(_units)==0:
+ logger.debug("find_best_next_schedulable_unit: no units to evaluate in window ['%s', '%s']",_lower_bound, _upper_bound)
+ return None
+
+ logger.info("find_best_next_schedulable_unit: evaluating constraints for %d %s-queue units in %dmin window ['%s', '%s']: %s",
+ len(_units),
+ _units[0].priority_queue.value,
+ (_upper_bound-_lower_bound).total_seconds()/60.0,
_lower_bound, _upper_bound,
','.join([str(su.id) for su in sorted(_units, key=lambda x: x.id)]) or 'None')
@@ -381,7 +390,9 @@ class Scheduler:
self._raise_if_triggered,
self.search_gridder)
- logger.info("find_best_next_schedulable_unit: units meeting constraints in window ['%s', '%s']: %s",
+ logger.info("find_best_next_schedulable_unit: %d units meeting constraints in %dmin window ['%s', '%s']: %s",
+ len(filtered_scheduling_units),
+ (_upper_bound-_lower_bound).total_seconds()/60.0,
_lower_bound,
_upper_bound,
','.join([str(su.id) for su in sorted(filtered_scheduling_units, key=lambda x: x.id)]) or 'None')
@@ -408,7 +419,9 @@ class Scheduler:
# then consider only those. Else, just use all.
units_to_score = exclusive_in_this_window_scheduling_units if exclusive_in_this_window_scheduling_units else filtered_scheduling_units
- logger.info("find_best_next_schedulable_unit: units to score in window ['%s', '%s']: %s",
+ logger.info("find_best_next_schedulable_unit: %d units to score in %dmin window ['%s', '%s']: %s",
+ len(units_to_score),
+ (_upper_bound-_lower_bound).total_seconds()/60.0,
_lower_bound,
_upper_bound,
','.join([str(su.id) for su in sorted(units_to_score, key=lambda x: x.id)]) or 'None')
@@ -426,19 +439,20 @@ class Scheduler:
# split the list of units in B-prio and non_B-prio
# try to find the best unit in the non_B first
scheduling_units_non_B = sorted([su for su in scheduling_units if su.priority_queue.value != models.PriorityQueueType.Choices.B.value], key=attrgetter('id'))
-
- best_scored_scheduling_unit = _do_find_best_next_schedulable_unit(scheduling_units_non_B, lower_bound_start_time, upper_bound_stop_time)
-
- if best_scored_scheduling_unit:
- _elapsed = datetime.utcnow() - _start_search_timestamp
- logger.info("find_best_next_schedulable_unit: best_scored_scheduling_unit id=%s name='%s' start='%s' in window ['%s', '%s'] (took %.2fs)",
- best_scored_scheduling_unit.scheduling_unit.id,
- best_scored_scheduling_unit.scheduling_unit.name,
- best_scored_scheduling_unit.start_time,
- lower_bound_start_time,
- upper_bound_stop_time,
- _elapsed.total_seconds())
- return best_scored_scheduling_unit
+ if scheduling_units_non_B:
+ best_scored_scheduling_unit = _do_find_best_next_schedulable_unit(scheduling_units_non_B, lower_bound_start_time, upper_bound_stop_time)
+
+ if best_scored_scheduling_unit:
+ _elapsed = datetime.utcnow() - _start_search_timestamp
+ logger.info("find_best_next_schedulable_unit: best_scored_scheduling_unit id=%s name='%s' start='%s' in %dmin window ['%s', '%s'] (took %.2fs)",
+ best_scored_scheduling_unit.scheduling_unit.id,
+ best_scored_scheduling_unit.scheduling_unit.name,
+ best_scored_scheduling_unit.start_time,
+ (upper_bound_stop_time-lower_bound_start_time).total_seconds()/60.0,
+ lower_bound_start_time,
+ upper_bound_stop_time,
+ _elapsed.total_seconds())
+ return best_scored_scheduling_unit
# ok, no best non-B unit was found. Try the B-units now.
scheduling_units_B = sorted([su for su in scheduling_units if su.priority_queue.value == models.PriorityQueueType.Choices.B.value], key=attrgetter('id'))
@@ -446,9 +460,10 @@ class Scheduler:
# because B-prio units cannot unschedule overlapping/blocking A/triggered units, we need to search for gaps between already scheduled units.
# and determine the scheduling search windows, taking into account the gaps between A/triggered units for B, or just the full window for A/triggered
# group the B-units by stations, because the (non-)overlapping stations determine to gap to existing scheduled units.
+ used_stations = set(get_used_stations_in_timewindow(lower_bound_start_time, upper_bound_stop_time))
grouped_by_stations_scheduling_units_B = {}
for unit_B in scheduling_units_B:
- stations = tuple(unit_B.main_observation_specified_stations)
+ stations = tuple(sorted(list(set(unit_B.main_observation_specified_stations)-used_stations)))
if stations not in grouped_by_stations_scheduling_units_B:
grouped_by_stations_scheduling_units_B[stations] = [unit_B]
else:
@@ -459,6 +474,10 @@ class Scheduler:
upper_bound_stop_time,
DEFAULT_INTER_OBSERVATION_GAP,
stations)
+ logger.info("find_best_next_schedulable_unit: gaps for %d units-with-stations=%s in window ['%s', '%s']: %s",
+ len(scheduling_units_B_group),
+ ','.join(stations), lower_bound_start_time, upper_bound_stop_time,
+ ', '.join("['%s', '%s']"%(gap[0],gap[1]) for gap in scheduling_windows_for_B))
for window in scheduling_windows_for_B:
best_scored_scheduling_unit = _do_find_best_next_schedulable_unit(scheduling_units_B_group,
@@ -479,7 +498,11 @@ class Scheduler:
return best_scored_scheduling_unit
_elapsed = datetime.utcnow() - _start_search_timestamp
- logger.info("find_best_next_schedulable_unit: could NOT find a best_scored_scheduling_unit in window ['%s', '%s'] (took %.2fs)", lower_bound_start_time, upper_bound_stop_time, _elapsed.total_seconds())
+ logger.info("find_best_next_schedulable_unit: could NOT find a best_scored_scheduling_unit in %dmin window ['%s', '%s'] (took %.2fs)",
+ (upper_bound_stop_time-lower_bound_start_time).total_seconds()/60.0,
+ lower_bound_start_time,
+ upper_bound_stop_time,
+ _elapsed.total_seconds())
return None
@@ -710,8 +733,12 @@ class Scheduler:
except RecursionError as e:
logger.error("Max recursion depth reached. Skipping further scheduling of B-queue units in %d[min]-wide gap( ['%s', '%s')", (upper_bound_stop_time-lower_bound_start_time).total_seconds()/60, lower_bound_start_time, upper_bound_stop_time)
else:
- logger.info("place_B_priority_units_in_gaps: could not find any B-queue unit out of the %d candidates which fits in gap ['%s', '%s') next to unit id=%s",
- schedulable_units_queue_B.count(), lower_bound_start_time, upper_bound_stop_time, scheduling_unit.id)
+ logger.info("place_B_priority_units_in_gaps: could not find any B-queue unit out of the %d candidates which fits in %dmin gap ['%s', '%s') next to unit id=%s",
+ schedulable_units_queue_B.count(),
+ (upper_bound_stop_time-lower_bound_start_time).total_seconds()/60.0,
+ lower_bound_start_time,
+ upper_bound_stop_time,
+ scheduling_unit.id)
return placed_units
@@ -813,7 +840,7 @@ class Scheduler:
task_center_time, transit_time, offset_to_transit, lowest_elevation, elevation_at_center, elevation_at_transit = get_timestamps_elevations_and_offset_to_transit(unit, unit.scheduled_start_time)
logger.log(log_level,
- " id=% 4d project=%s q=%s gap=%5d[min] start_time='%s'[UTC] duration=%4d[min] status=%s name=%s centralLST='%s' transit_offset=% 5d[min] elv@transit=% 3.1f[deg] elv@center=% 3.1f[deg] elv_lowest=% 3.1f[deg] C/R/I=%s",
+ " id=% 4d %s %s gap=%5d[min] start_time='%s'[UTC] dur=%4d[min] %s name=%s midLST='%s' transit_offset=% 5d[min] elv@tr=% 3.1f[deg] elv@mid=% 3.1f[deg] elv_min=% 3.1f[deg] C/R/I=%s",
unit.id,
("'%s'" % (unit.project.name[:8],)).ljust(10),
unit.priority_queue.value,
diff --git a/SAS/TMSS/backend/src/tmss/tmssapp/subtasks.py b/SAS/TMSS/backend/src/tmss/tmssapp/subtasks.py
index b26ef30c1d3f87a53a92c37d628d58f6e4c86126..6dca3e5eb55ad5544642d336fb9a2c4e88831b4e 100644
--- a/SAS/TMSS/backend/src/tmss/tmssapp/subtasks.py
+++ b/SAS/TMSS/backend/src/tmss/tmssapp/subtasks.py
@@ -2590,9 +2590,7 @@ def get_gaps_to_previous_and_next_observations(subtask: Subtask, exclude_subtask
return ((datetime.min, datetime.max), (datetime.min, datetime.max))
# prepare query for non-obsolete non-cancelled/error observations
- qs = Subtask.objects.filter(specifications_template__type__value=SubtaskType.Choices.OBSERVATION.value)
- qs = qs.filter(obsolete_since__isnull=True)
- qs = qs.exclude(state__value__in=(SubtaskState.Choices.CANCELLED.value, SubtaskState.Choices.ERROR.value))
+ qs = Subtask.objects.filter(specifications_template__type__value=SubtaskType.Choices.OBSERVATION.value).filter(obsolete_since__isnull=True).exclude(state__value__in=(SubtaskState.Choices.CANCELLED.value, SubtaskState.Choices.ERROR.value))
# non-placed units do not have a relevant start/stoptime.
qs = qs.exclude(Q(placed=False) and Q(state__value=SubtaskState.Choices.DEFINED.value))
diff --git a/SAS/TMSS/backend/src/tmss/tmssapp/tasks.py b/SAS/TMSS/backend/src/tmss/tmssapp/tasks.py
index da9cef47b8926847ecd95be9f95a9ecf6cf0930e..8cef397022682b5a6fdca54e105131b0b896ffa9 100644
--- a/SAS/TMSS/backend/src/tmss/tmssapp/tasks.py
+++ b/SAS/TMSS/backend/src/tmss/tmssapp/tasks.py
@@ -949,11 +949,11 @@ def get_gaps_to_previous_and_next_observations_in_scheduling_unit(scheduling_uni
own_observation_subtasks = scheduling_unit.subtasks.filter(specifications_template__type__value='observation').filter(obsolete_since__isnull=True).all()
# get all gaps, exclude observations in this unit.
- results = [get_gaps_to_previous_and_next_observations(s,
+ results = [get_gaps_to_previous_and_next_observations(obs_subtask,
exclude_subtasks=own_observation_subtasks,
include_defined_unschedulable=include_schedulable_unschedulable,
- stations=scheduling_unit.main_observation_specified_stations)
- for s in own_observation_subtasks]
+ stations=obs_subtask.stations)
+ for obs_subtask in own_observation_subtasks]
# gather overall gaps.
overall_result = [[results[0][0][0], results[0][0][1]], [results[0][1][0], results[0][1][1]]]