Device component:

- Instrumented ConfigureDevice method

src/device/service/DeviceServiceServicerImpl.py

@@ -12,9 +12,10 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
+import grpc, logging, time, uuid
 from typing import Dict
-import grpc, logging
-from common.method_wrappers.Decorator import MetricsPool, safe_and_metered_rpc_method
+from prometheus_client import Histogram
+from common.method_wrappers.Decorator import MetricTypeEnum, MetricsPool, safe_and_metered_rpc_method
 from common.method_wrappers.ServiceExceptions import NotFoundException, OperationFailedException
 from common.proto.context_pb2 import (
     Device, DeviceConfig, DeviceDriverEnum, DeviceId, DeviceOperationalStatusEnum, Empty, Link)
@@ -36,6 +37,10 @@ LOGGER = logging.getLogger(__name__)
 
 METRICS_POOL = MetricsPool('Device', 'RPC')
 
+METRICS_POOL_DETAILS = MetricsPool('Device', 'exec_details', labels={
+    'step_name': '',
+})
+
 class DeviceServiceServicerImpl(DeviceServiceServicer):
     def __init__(self, driver_instance_cache : DriverInstanceCache, monitoring_loops : MonitoringLoops) -> None:
         LOGGER.debug('Creating Servicer...')
@@ -117,18 +122,22 @@ class DeviceServiceServicerImpl(DeviceServiceServicer):
 
     @safe_and_metered_rpc_method(METRICS_POOL, LOGGER)
     def ConfigureDevice(self, request : Device, context : grpc.ServicerContext) -> DeviceId:
+        t0 = time.time()
         device_id = request.device_id
         device_uuid = device_id.device_uuid.uuid
 
         self.mutex_queues.wait_my_turn(device_uuid)
+        t1 = time.time()
         try:
             context_client = ContextClient()
+            t2 = time.time()
             device = get_device(
                 context_client, device_uuid, rw_copy=True, include_endpoints=False, include_components=False,
                 include_config_rules=True)
             if device is None:
                 raise NotFoundException('Device', device_uuid, extra_details='loading in ConfigureDevice')
 
+            t3 = time.time()
             device_controller_uuid = get_device_controller_uuid(device)
             if device_controller_uuid is not None:
                 device = get_device(
@@ -159,13 +168,17 @@ class DeviceServiceServicerImpl(DeviceServiceServicer):
             if request.device_operational_status != DeviceOperationalStatusEnum.DEVICEOPERATIONALSTATUS_UNDEFINED:
                 device.device_operational_status = request.device_operational_status
 
+            t4 = time.time()
             # TODO: use of datastores (might be virtual ones) to enable rollbacks
             resources_to_set, resources_to_delete = compute_rules_to_add_delete(device, request)
 
+            t5 = time.time()
             errors = []
             errors.extend(configure_rules(device, driver, resources_to_set))
+            t6 = time.time()
             errors.extend(deconfigure_rules(device, driver, resources_to_delete))
 
+            t7 = time.time()
             if len(errors) > 0:
                 for error in errors: LOGGER.error(error)
                 raise OperationFailedException('ConfigureDevice', extra_details=errors)
@@ -176,8 +189,23 @@ class DeviceServiceServicerImpl(DeviceServiceServicer):
             # TODO: Add logic to inspect endpoints and keep only those ones modified with respect to Context.
             del device.device_endpoints[:]
 
+            t8 = time.time()
             # Note: Rules are updated by configure_rules() and deconfigure_rules() methods.
             device_id = context_client.SetDevice(device)
+
+            t9 = time.time()
+
+            histogram_duration : Histogram = METRICS_POOL_DETAILS.get_or_create(
+                'ConfigureDevice', MetricTypeEnum.HISTOGRAM_DURATION)
+            histogram_duration.labels(step_name='total'            ).observe(t9-t0)
+            histogram_duration.labels(step_name='wait_queue'       ).observe(t1-t0)
+            histogram_duration.labels(step_name='execution'        ).observe(t9-t1)
+            histogram_duration.labels(step_name='get_device'       ).observe(t3-t2)
+            histogram_duration.labels(step_name='split_rules'      ).observe(t5-t4)
+            histogram_duration.labels(step_name='configure_rules'  ).observe(t6-t5)
+            histogram_duration.labels(step_name='deconfigure_rules').observe(t7-t6)
+            histogram_duration.labels(step_name='set_device'       ).observe(t9-t8)
+
             return device_id
         finally:
             self.mutex_queues.signal_done(device_uuid)