diff --git a/src/device/service/DeviceServiceServicerImpl.py b/src/device/service/DeviceServiceServicerImpl.py index 6567935f432f0fa8895b6e1b7695deeadcf443f8..cd6332cc5bcf0967fa4894e67dfa0f317104ee18 100644 --- a/src/device/service/DeviceServiceServicerImpl.py +++ b/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)