TMSS-190: processed review comments. Factored out block of code into method...

TMSS-190: processed review comments. Factored out block of code into method unschededule_blocking_scheduled_units_if_needed_and_possible

SAS/TMSS/services/scheduling/lib/dynamic_scheduling.py

@@ -60,6 +60,39 @@ def get_scheduled_scheduling_units(lower:datetime=None, upper:datetime=None) ->
     return list(models.SchedulingUnitBlueprint.objects.filter(id__in=scheduled_subtasks.values('task_blueprint__scheduling_unit_blueprint_id').distinct()).all())
 
 
+def unschededule_blocking_scheduled_units_if_needed_and_possible(candidate: ScoredSchedulingUnit) -> bool:
+    '''check if there are any already scheduled units in the way, and unschedule them if allowed. Return True if nothing is blocking anymore.'''
+    # check any previously scheduled units, and unschedule if needed/allowed
+    scheduled_scheduling_units = get_scheduled_scheduling_units(lower=candidate.start_time,
+                                                                upper=candidate.start_time + candidate.scheduling_unit.duration)
+
+    # check if we can and need to unschedule the blocking units
+    for scheduled_scheduling_unit in scheduled_scheduling_units:
+        scheduled_score = compute_scores(scheduled_scheduling_unit, candidate.start_time, candidate.start_time + candidate.scheduling_unit.duration)
+
+        if candidate.weighted_score > scheduled_score.weighted_score:
+            # ToDo: also check if the scheduled_scheduling_unit is manually/dynamically scheduled
+            logger.info("unscheduling id=%s '%s' because it is in the way and has a lower score than the best candidate id=%s '%s' score=%s start_time=%s",
+                scheduled_scheduling_unit.id, scheduled_scheduling_unit.name,
+                candidate.scheduling_unit.id, candidate.scheduling_unit.name, candidate.weighted_score, candidate.scheduling_unit.start_time)
+
+            unschedule_subtasks_in_scheduling_unit_blueprint(scheduled_scheduling_unit)
+
+    # check again... are still there any scheduled_scheduling_units in the way?
+    scheduled_scheduling_units = get_scheduled_scheduling_units(lower=candidate.start_time,
+                                                                upper=candidate.start_time + candidate.scheduling_unit.duration)
+    if scheduled_scheduling_units:
+        # accept current solution with current scheduled_scheduling_units
+        logger.info("keeping current scheduled unit(s) which have a better (or equal) score: %s", "; ".join(
+            "id=%s '%s' start_time='%s'" % (su.id, su.name, su.start_time) for su in scheduled_scheduling_units))
+
+        # indicate there are still blocking units
+        return False
+
+    # all clear, nothing is blocking anymore
+    return True
+
+
 def find_best_next_schedulable_unit(scheduling_units:[models.SchedulingUnitBlueprint], lower_bound_start_time: datetime, upper_bound_stop_time: datetime) -> ScoredSchedulingUnit:
     """
     find the best schedulable scheduling_unit which can run withing the given time window from the given scheduling_units.
@@ -107,7 +140,7 @@ def schedule_next_scheduling_unit() -> models.SchedulingUnitBlueprint:
     while lower_bound_start_time < upper_bound_stop_time:
         try:
             # try to find the best next scheduling_unit
-            logger.info("schedule_next_scheduling_unit: searching for best scheduling unit to schedule starting between '%s' and '%s'", lower_bound_start_time, upper_bound_stop_time)
+            logger.info("schedule_next_scheduling_unit: searching for best scheduling unit to schedule between '%s' and '%s'", lower_bound_start_time, upper_bound_stop_time)
             best_scored_scheduling_unit = find_best_next_schedulable_unit(schedulable_units, lower_bound_start_time, upper_bound_stop_time)
             if best_scored_scheduling_unit:
                 best_scheduling_unit = best_scored_scheduling_unit.scheduling_unit
@@ -120,31 +153,14 @@ def schedule_next_scheduling_unit() -> models.SchedulingUnitBlueprint:
                 logger.info("schedule_next_scheduling_unit: found best candidate id=%s '%s' weighted_score=%s start_time=%s",
                             best_scheduling_unit.id, best_scheduling_unit.name, best_scheduling_unit_score, best_start_time)
 
-                # check any previously scheduled units, and unschedule if needed/allowed
-                scheduled_scheduling_units = get_scheduled_scheduling_units(lower=best_start_time, upper=best_start_time+best_scheduling_unit.duration)
-                for scheduled_scheduling_unit in scheduled_scheduling_units:
-                    if best_scheduling_unit_score > compute_scores(scheduled_scheduling_unit, lower_bound_start_time, upper_bound_stop_time).weighted_score:
-                        logger.info("schedule_next_scheduling_unit: unscheduling id=%s '%s' because it is in the way and has a lower score than the best candidate id=%s '%s' score=%s start_time=%s",
-                                    scheduled_scheduling_unit.id, scheduled_scheduling_unit.name,
-                                    best_scheduling_unit.id, best_scheduling_unit.name, best_scheduling_unit_score, best_start_time)
-                        unschedule_subtasks_in_scheduling_unit_blueprint(scheduled_scheduling_unit)
-
-                # check again... are still there any scheduled_scheduling_units in the way?
-                scheduled_scheduling_units = get_scheduled_scheduling_units(lower=best_start_time, upper=best_start_time+best_scheduling_unit.duration)
-                if scheduled_scheduling_units:
-                    # accept current solution with current scheduled_scheduling_units
-                    logger.info("schedule_next_scheduling_unit: keeping current scheduled unit(s) which have a better (or equal) score: %s",
-                                "; ".join("id=%s '%s' start_time='%s'" % (su.id, su.name, su.start_time) for su in scheduled_scheduling_units))
-                    return None
-                else:
-                    # no (old) scheduled scheduling_units in the way, so
-                    # schedule our candidate!
-                    logger.info("schedule_next_scheduling_unit: scheduling best candidate id=%s '%s' score=%s start_time=%s",
-                                best_scheduling_unit.id, best_scheduling_unit.name, best_scheduling_unit_score, best_start_time)
+                if unschededule_blocking_scheduled_units_if_needed_and_possible(best_scored_scheduling_unit):
+                    # no (old) scheduled scheduling_units in the way, so schedule our candidate!
                     scheduled_scheduling_unit = schedule_independent_subtasks_in_scheduling_unit_blueprint(best_scheduling_unit, start_time=best_start_time)
+
                     logger.info("schedule_next_scheduling_unit: scheduled best candidate id=%s '%s' score=%s start_time=%s",
                                 best_scheduling_unit.id, best_scheduling_unit.name, best_scheduling_unit_score, best_start_time)
                     return scheduled_scheduling_unit
+
         except SubtaskSchedulingException as e:
             logger.error("Could not schedule scheduling_unit id=%s name='%s'. Error: %s", best_scheduling_unit.id, best_scheduling_unit.name, e)
 
@@ -213,6 +229,7 @@ def schedule_next_scheduling_unit_and_assign_start_stop_times_to_remaining_sched
     # round up to next nearest second
     lower_bound_start_time += timedelta(microseconds=1000000-lower_bound_start_time.microsecond)
 
+    # determine mid-term schedule by assigning start/stop times to remaining schedulable units using the same search strategy
     assign_start_stop_times_to_schedulable_scheduling_units(lower_bound_start_time)
     logger.info("Finished updating dynamic schedule")
 
@@ -224,7 +241,7 @@ class TMSSSchedulingUnitBlueprintDynamicSchedulingMessageHandler(TMSSEventMessag
     '''
 
     def __init__(self):
-        super().__init__()
+        super().__init__(log_event_messages=True)
         self._scheduling_thread = None
         self._scheduling_thread_running = False
         self._do_schedule_event = Event()