Task #9893: Improved logging and added missing exception handeling

SAS/ResourceAssignment/ResourceAssigner/lib/raservice.py

@@ -63,7 +63,7 @@ class SpecifiedTaskListener(RATaskSpecifiedBusListener):
             self.assigner = ResourceAssigner()
 
     def onTaskSpecified(self, otdb_id, specification_tree):
-        logger.info('onTaskSpecified: otdb_id=%s' % otdb_id)
+        logger.info('onTaskSpecified: otdb_id=%s status=%s', otdb_id, specification_tree.get('state', '').lower())
 
         try:
             self.assigner.do_assignment(otdb_id, specification_tree)

SAS/ResourceAssignment/ResourceAssigner/lib/resource_assigner.py

@@ -201,8 +201,13 @@ class ResourceAssigner(object):
                     # Scheduling of resources for this task succeeded, so change task status to "scheduled"
                     self._finish_resource_assignment(task, 'scheduled')
                 else:
-                    # Scheduling of resources for this task failed, so change task status to "conflict"
-                    self._finish_resource_assignment(task, 'conflict')
+                    # Scheduling of resources for this task failed,
+                    # check if any of the claims has status conflict,
+                    # and hence (by the radb triggers) the task has status conflict as well
+                    # if task not in conflict, then there was a specification/scheduling error
+                    # so put task status to error (not conflict!)
+                    if self.radbrpc.getTask(task['id'])['status'] != 'conflict':
+                        self._finish_resource_assignment(task, 'error')
 
     def _insert_specification_into_radb(self, otdb_id, specification_tree):
         """
@@ -433,6 +438,8 @@ class ResourceAssigner(object):
                      specified, or where specified in a wrong format.
             """
 
+            logger.debug('_get_start_and_end_time_from_parset - parset: %s', _parset)
+
             try:
                 parset_start_time = parseDatetime(_parset.getString('Observation.startTime'))
             except ValueError or KeyError:
@@ -654,7 +661,11 @@ class ResourceAssigner(object):
                                    max_starttime=start_time,
                                    duration=end_time - start_time)
 
-        result = scheduler.allocate_resources(requested_resources)
+        try:
+            result = scheduler.allocate_resources(requested_resources)
+        except Exception as e:
+            logger.error('Error in calling scheduler.allocate_resources: %s', e)
+            result = False
 
         if result:
             logger.info('Resources successfully allocated task_id=%s' % task_id)

SAS/ResourceAssignment/ResourceAssigner/lib/schedulers.py

@@ -12,6 +12,9 @@ from lofar.sas.resourceassignment.resourceassigner.resource_availability_checker
 from lofar.mac.config import DEFAULT_OBSERVATION_CONTROL_BUS_NAME, DEFAULT_OBSERVATION_CONTROL_SERVICE_NAME
 from lofar.mac.observation_control_rpc import ObservationControlRPCClient
 
+import logging
+logger = logging.getLogger(__name__)
+
 
 """ Scheduling is the process of looking for a suitable resource slot for a given task.
 
@@ -96,7 +99,8 @@ class BasicScheduler(object):
             self.radb.commit()
 
             allocation_successful = True
-        except ScheduleException:
+        except ScheduleException as se:
+            logger.error('ScheduleException in allocate_resources: %s', se)
             self.radb.rollback()
 
         return allocation_successful
@@ -171,7 +175,8 @@ class BasicScheduler(object):
         try:
             tentative_claims = self.resource_availability_checker.get_is_claimable(requested_resources,
                                                                                    available_resources)
-        except CouldNotFindClaimException:
+        except CouldNotFindClaimException as e:
+            logger.error('_try_schedule CouldNotFindClaimException: %s', e)
             raise ScheduleException("Could not schedule")
 
         # add static info to all claims