diff --git a/SAS/TMSS/backend/src/tmss/workflowapp/tests/t_workflow_qaworkflow.py b/SAS/TMSS/backend/src/tmss/workflowapp/tests/t_workflow_qaworkflow.py index 0cc689350db18a1be61caa24238008c00c3b7032..332c5b04d13e5d6b6f03482d5bd0b362fca49b46 100755 --- a/SAS/TMSS/backend/src/tmss/workflowapp/tests/t_workflow_qaworkflow.py +++ b/SAS/TMSS/backend/src/tmss/workflowapp/tests/t_workflow_qaworkflow.py @@ -4,7 +4,7 @@ import requests import json import logging -logger = logging.getLogger(__name__) +logger = logging.getLogger('lofar.'+__name__) logging.basicConfig(format='%(asctime)s %(levelname)s %(message)s', level=logging.INFO) from lofar.common.test_utils import skip_integration_tests @@ -42,6 +42,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): SchedulingUnitFlowTest.sync_event_bp_observed.set() def setUp(self) -> None: + logger.info('---------------------------------------------------------------------------------') self.sync_event_bp_scheduled.clear() self.sync_event_bp_observed.clear() @@ -115,8 +116,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.filter(su=scheduling_unit_blueprint).count() > 0: break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("SchedulingUnitProcess not created within expected time") # Yes! the SchedulingUnitProcess was created, let's get it. @@ -142,6 +143,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): set_subtask_state_following_allowed_transitions(subtask, 'scheduled') # wait until scheduling unit is scheduled + logging.info("waiting for sync_event_bp_scheduled...") if not self.sync_event_bp_scheduled.wait(timeout=10): logging.info("sync_event_bp_scheduled event not received, raising TimeoutError") raise TimeoutError() @@ -151,8 +153,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "wait_observed": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_scheduled.clear() @@ -172,6 +174,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): for subtask in task_blueprint.subtasks.all(): set_subtask_state_following_allowed_transitions(subtask, 'finished') + logging.info("waiting for sync_event_bp_observed...") if not self.sync_event_bp_observed.wait(timeout=10): logging.info("sync_event_bp_observed event not received, raising TimeoutError") raise TimeoutError() @@ -181,8 +184,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "qa_reporting_to": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_observed.clear() @@ -409,8 +412,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.filter(su=scheduling_unit_blueprint).count() > 0: break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("SchedulingUnitProcess not created within expected time") # Yes! the SchedulingUnitProcess was created, let's get it. @@ -436,6 +439,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): set_subtask_state_following_allowed_transitions(subtask, 'scheduled') # wait until scheduling unit is scheduled + logging.info("waiting for sync_event_bp_scheduled...") if not self.sync_event_bp_scheduled.wait(timeout=10): logging.info("sync_event_bp_scheduled event not received, raising TimeoutError") raise TimeoutError() @@ -445,8 +449,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "wait_observed": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_scheduled.clear() @@ -470,6 +474,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): for subtask in task_blueprint.subtasks.all(): set_subtask_state_following_allowed_transitions(subtask, 'finished') + logging.info("waiting for sync_event_bp_observed...") if not self.sync_event_bp_observed.wait(timeout=10): logging.info("sync_event_bp_observed event not received, raising TimeoutError") raise TimeoutError() @@ -479,8 +484,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "qa_reporting_to": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_observed.clear() @@ -603,8 +608,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.filter(su=scheduling_unit_blueprint).count() > 0: break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("SchedulingUnitProcess not created within expected time") # Yes! the SchedulingUnitProcess was created, let's get it. @@ -630,6 +635,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): set_subtask_state_following_allowed_transitions(subtask, 'scheduled') # wait until scheduling unit is scheduled + logging.info("waiting for sync_event_bp_scheduled...") if not self.sync_event_bp_scheduled.wait(timeout=10): logging.info("sync_event_bp_scheduled event not received, raising TimeoutError") raise TimeoutError() @@ -639,8 +645,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "wait_observed": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_scheduled.clear() @@ -664,6 +670,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): for subtask in task_blueprint.subtasks.all(): set_subtask_state_following_allowed_transitions(subtask, 'finished') + logging.info("waiting for sync_event_bp_observed...") if not self.sync_event_bp_observed.wait(timeout=10): logging.info("sync_event_bp_observed event not received, raising TimeoutError") raise TimeoutError() @@ -673,8 +680,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "qa_reporting_to": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_observed.clear() @@ -824,8 +831,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.filter(su=scheduling_unit_blueprint).count() > 0: break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("SchedulingUnitProcess not created within expected time") # Yes! the SchedulingUnitProcess was created, let's get it. @@ -851,6 +858,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): set_subtask_state_following_allowed_transitions(subtask, 'scheduled') # wait until scheduling unit is scheduled + logging.info("waiting for sync_event_bp_scheduled...") if not self.sync_event_bp_scheduled.wait(timeout=10): logging.info("sync_event_bp_scheduled event not received, raising TimeoutError") raise TimeoutError() @@ -860,8 +868,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "wait_observed": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_scheduled.clear() @@ -885,6 +893,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): for subtask in task_blueprint.subtasks.all(): set_subtask_state_following_allowed_transitions(subtask, 'finished') + logging.info("waiting for sync_event_bp_observed...") if not self.sync_event_bp_observed.wait(timeout=10): logging.info("sync_event_bp_observed event not received, raising TimeoutError") raise TimeoutError() @@ -894,8 +903,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "qa_reporting_to": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_observed.clear() @@ -1104,8 +1113,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.filter(su=scheduling_unit_blueprint).count() > 0: break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("SchedulingUnitProcess not created within expected time") # Yes! the SchedulingUnitProcess was created, let's get it. @@ -1131,6 +1140,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): set_subtask_state_following_allowed_transitions(subtask, 'scheduled') # wait until scheduling unit is scheduled + logging.info("waiting for sync_event_bp_scheduled...") if not self.sync_event_bp_scheduled.wait(timeout=10): logging.info("sync_event_bp_scheduled event not received, raising TimeoutError") raise TimeoutError() @@ -1140,8 +1150,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "wait_observed": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_scheduled.clear() @@ -1165,6 +1175,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): for subtask in task_blueprint.subtasks.all(): set_subtask_state_following_allowed_transitions(subtask, 'finished') + logging.info("waiting for sync_event_bp_observed...") if not self.sync_event_bp_observed.wait(timeout=10): logging.info("sync_event_bp_observed event not received, raising TimeoutError") raise TimeoutError() @@ -1174,8 +1185,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[0].flow_task.name == "qa_reporting_to": break - sleep(0.1) - if datetime.utcnow()-poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow()-poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_observed.clear() @@ -1376,8 +1387,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): while True: if SchedulingUnitProcess.objects.filter(su=scheduling_unit_blueprint).count() > 0: break - sleep(0.1) - if datetime.utcnow() - poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow() - poll_starttime > timedelta(seconds=30): raise TimeoutError("SchedulingUnitProcess not created within expected time") # Yes! the SchedulingUnitProcess was created, let's get it. @@ -1403,6 +1414,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): set_subtask_state_following_allowed_transitions(subtask, 'scheduled') # wait until scheduling unit is scheduled + logging.info("waiting for sync_event_bp_scheduled...") if not self.sync_event_bp_scheduled.wait(timeout=10): logging.info("sync_event_bp_scheduled event not received, raising TimeoutError") raise TimeoutError() @@ -1413,8 +1425,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[ 0].flow_task.name == "wait_observed": break - sleep(0.1) - if datetime.utcnow() - poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow() - poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_scheduled.clear() @@ -1441,6 +1453,7 @@ class SchedulingUnitFlowTest(unittest.TestCase): for subtask in task_blueprint.subtasks.all(): set_subtask_state_following_allowed_transitions(subtask, 'finished') + logging.info("waiting for sync_event_bp_observed...") if not self.sync_event_bp_observed.wait(timeout=10): logging.info("sync_event_bp_observed event not received, raising TimeoutError") raise TimeoutError() @@ -1451,8 +1464,8 @@ class SchedulingUnitFlowTest(unittest.TestCase): if SchedulingUnitProcess.objects.get(su=scheduling_unit_blueprint.id).active_tasks()[ 0].flow_task.name == "qa_reporting_to": break - sleep(0.1) - if datetime.utcnow() - poll_starttime > timedelta(seconds=10): + sleep(0.5) + if datetime.utcnow() - poll_starttime > timedelta(seconds=30): raise TimeoutError("Task not activated within expected time") self.sync_event_bp_observed.clear()