diff --git a/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py b/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py index bff71d033ab4c13f79bf42430a3604e13236ecea..9967108abc915d19ef43b2a5a55380a715bd4c23 100644 --- a/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py +++ b/SAS/TMSS/backend/services/scheduling/lib/dynamic_scheduling.py @@ -643,7 +643,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 queue=%s name=%s start_time='%s'[UTC] duration=% 3d[min] status=%s centralLST='%s' transit_offset=% 5d[min] elv@transit=% 3.1f[deg] elv@center=% 3.1f[deg] elv_lowest=% 3.1f[deg]", + " id=% 4d queue=%s name=%s start_time='%s'[UTC] duration=% 4d[min] status=%s centralLST='%s' transit_offset=% 5d[min] elv@transit=% 3.1f[deg] elv@center=% 3.1f[deg] elv_lowest=% 3.1f[deg]", unit.id, unit.priority_queue.value, ("'%s'" % (unit.name[:32],)).ljust(34), diff --git a/SAS/TMSS/backend/services/scheduling/test/t_dynamic_scheduling.py b/SAS/TMSS/backend/services/scheduling/test/t_dynamic_scheduling.py index cd9364b1b8db70dbe420ca24b511f5e0e5b94ff7..b40ae6581fd4ecdca4a72a9cae1fdd0392a75f06 100755 --- a/SAS/TMSS/backend/services/scheduling/test/t_dynamic_scheduling.py +++ b/SAS/TMSS/backend/services/scheduling/test/t_dynamic_scheduling.py @@ -457,10 +457,160 @@ class TestFixedTimeScheduling(BaseDynamicSchedulingTestCase): self.assertEqual(models.SchedulingUnitStatus.Choices.SCHEDULED.value, scheduling_unit_blueprint.status.value) self.assertEqual(at, scheduling_unit_blueprint.scheduled_start_time) + def test_bug_fix_TMSS_2302_unschedulable_reason_too_generic(self): + """ + Test to reproduce the reported bug that a fixed_time unit does not state a specific unschedulable reason. + See: https://support.astron.nl/jira/browse/TMSS-2302 + We are using the specs from https://tmss.lofar.eu/schedulingunit/view/blueprint/2004 which had troubles being scheduled. + """ + project = models.Project.objects.create(**Project_test_data(name=str(uuid.uuid4()), auto_ingest=True, + project_state=models.ProjectState.objects.get(value=models.ProjectState.Choices.ACTIVE.value))) + + cycle = models.Cycle.objects.create(name=str(uuid.uuid4()), + start=datetime.utcnow()-timedelta(days=1), + stop=datetime.utcnow() + timedelta(days=7)) + cycle.projects.set([project]) + cycle.save() + + scheduling_set = models.SchedulingSet.objects.create(**SchedulingSet_test_data(project=project)) + + at = datetime(2023, 3, 30, 18, 40) #round_to_second_precision(datetime.utcnow() + timedelta(days=1)) + strategy_template = models.SchedulingUnitObservingStrategyTemplate.get_latest(name="IM HBA LoTSS - 2 Beams") + su_draft = create_scheduling_unit_draft_from_observing_strategy_template(strategy_template, scheduling_set=scheduling_set, + specifications_doc_overrides={ + "scheduling_constraints_doc": { + "daily": { + "avoid_twilight": False, + "require_day": False, + "require_night": False + }, + "scheduler": "fixed_time", + "sky": { + "min_distance": { + "jupiter": 0.2617993877991494, + "moon": 0.3490658503988659, + "sun": 0.5235987755982988 + }, + "min_elevation": { + "calibrator": 0.5235987755982988, + "target": 0.5235987755982988 + }, + "transit_offset": { + "from": -3600, + "to": 3600 + } + }, + "time": { + "at": at.isoformat() + } + }, + "tasks": { + "Calibrator Observation 1": { + "short_description": "Cal 3C196", + "specifications_doc": { + "calibrator": { + "pointing": { + "angle1": 2.1537413875046543, + "angle2": 0.8415517080119602, + "direction_type": "J2000", + "target": "3C196" + } + } + } + }, + "Calibrator Observation 2": { + "short_description": "Cal 3C295", + "specifications_doc": { + "calibrator": { + "pointing": { + "angle1": 3.714680167406339, + "angle2": 0.9111102054650467, + "direction_type": "J2000", + "target": "3C295" + } + } + } + }, + "Calibrator Pipeline 1": { + "short_description": "Cal1 3C196/PP" + }, + "Calibrator Pipeline 2": { + "short_description": "Cal2 3C295/PP" + }, + "Pipeline target1": { + "short_description": "COSMOS/TP" + }, + "Pipeline target2": { + "short_description": "P145+04/TP" + }, + "Target Observation": { + "short_description": "COSMOS_P145+04", + "specifications_doc": { + "duration": 14400, + "station_configuration": { + "SAPs": [ + { + "digital_pointing": { + "angle1": 2.620073728683454, + "angle2": 0.038499054416908256, + "direction_type": "J2000", + "target": "COSMOS" + } + }, + { + "digital_pointing": { + "angle1": 2.5359372232089807, + "angle2": 0.07651038627062032, + "direction_type": "J2000", + "target": "P145+04" + } + } + ], + "station_groups": [ + { + "max_nr_missing": 4, + "stations": [ "CS002", "CS003", "CS004", "CS005", "CS006", "CS007", "CS011", "CS013", "CS017", "CS021", "CS024", "CS026", "CS028", "CS030", "CS031", "CS032", "CS101", "CS103", "CS201", "CS301", "CS302", "CS401", "CS501", "RS106", "RS205", "RS208", "RS210", "RS305", "RS306", "RS307", "RS310", "RS406", "RS407", "RS409", "RS503", "RS508", "RS509"] + }, + { + "max_nr_missing": 2, + "stations": ["DE601", "DE602", "DE603", "DE604", "DE605", "DE609", "FR606", "SE607", "UK608", "PL610", "PL611", "PL612", "IE613", "LV614"] + }, + { + "max_nr_missing": 1, + "stations": ["DE601", "DE605"] + } + ], + "tile_beam": { + "angle1": 2.578006639499052, + "angle2": 0.05750510819470917, + "direction_type": "J2000", + "target": "COSMOSP145+04REF" + } + } + } + } + } + }) + scheduling_unit_blueprint = create_scheduling_unit_blueprint_and_tasks_and_subtasks_from_scheduling_unit_draft(su_draft) + + # assert blueprint has correct constraints, and is schedulable + self.assertEqual('fixed_time', scheduling_unit_blueprint.scheduling_constraints_doc['scheduler']) + self.assertEqual(at.isoformat(), scheduling_unit_blueprint.scheduling_constraints_doc['time']['at']) + self.assertEqual(scheduling_unit_blueprint.status.value, models.SchedulingUnitStatus.Choices.SCHEDULABLE.value) + + self.scheduler.schedule_fixed_time_scheduling_units() + + # Assert the scheduling_unit is unschedulable, and has a specific unschedulable_reason + scheduling_unit_blueprint.refresh_from_db() + self.assertEqual(models.SchedulingUnitStatus.Choices.UNSCHEDULABLE.value, scheduling_unit_blueprint.status.value) + # the bug yields a generic reason: constraint time.at='2023-03-30 18:40:00' falls outside of window ['2023-03-30 18:40:00', '2023-03-30 22:40:00'] + # but the root cause of unschedulability is: "sky.min_elevation is not met at evaluation='2023-03-30 19:00:00'" + # we want to see that message in the unschedulable_reason, which is currently not the case. + self.assertNotIn('falls outside of window', scheduling_unit_blueprint.unschedulable_reason) - def test_excetion_during_scheduling_sets_state_to_unschedulable(self): + def test_exception_during_scheduling_sets_state_to_unschedulable(self): """ Test a simple observation with the 'at' constraint and 'fixed_time' scheduler. When an exception is raised during scheduling, the state should go to unschedulable so the user can retry/fix. @@ -3224,8 +3374,8 @@ class TestTriggers(BaseDynamicSchedulingTestCase): logging.basicConfig(format='%(asctime)s %(levelname)s %(message)s', level=logging.INFO) # # uncomment to show debug messages for scheduling modules -# logging.getLogger('lofar.sas.tmss.services.scheduling').level = logging.DEBUG -# logging.getLogger('lofar.sas.tmss.tmss.tmssapp.subtasks').level = logging.DEBUG +logging.getLogger('lofar.sas.tmss.services.scheduling').level = logging.DEBUG +logging.getLogger('lofar.sas.tmss.tmss.tmssapp.subtasks').level = logging.DEBUG # hide spam of postgreslistener messages logging.getLogger('lofar.sas.tmss.services.tmss_postgres_listener').disabled = True