diff --git a/inventory_provider/db/ims.py b/inventory_provider/db/ims.py index d7b4eebd7297576c0936b5b2461bfca3117702f8..7ff0762b263073526174465792aef1e8a5262c94 100644 --- a/inventory_provider/db/ims.py +++ b/inventory_provider/db/ims.py @@ -1,9 +1,11 @@ +from enum import Enum +import functools import logging +import time import requests -import time -from enum import Enum +from inventory_provider import environment # Navigation Properties @@ -11,6 +13,9 @@ from enum import Enum from requests import HTTPError logger = logging.getLogger(__name__) +log_entry_and_exit = functools.partial( + environment.log_entry_and_exit, logger=logger) + # http://149.210.162.190:81/ImsVersions/21.9/html/50e6a1b1-3910-2091-63d5-e13777b2194e.htm # noqa CIRCUIT_CUSTOMER_RELATION = { @@ -317,6 +322,7 @@ class IMS(object): IMS.cache[cache_key] = return_value return return_value + @log_entry_and_exit def get_entity_by_id( self, entity_type, @@ -328,6 +334,7 @@ class IMS(object): return \ self._get_entity(url, None, navigation_properties, use_cache) + @log_entry_and_exit def get_entity_by_name( self, entity, @@ -337,6 +344,7 @@ class IMS(object): url = f'{entity}/byname/"{name}"' return self._get_entity(url, None, navigation_properties, use_cache) + @log_entry_and_exit def get_filtered_entities( self, entity, @@ -372,6 +380,7 @@ class IMS(object): start_entity += step_count yield from entities + @log_entry_and_exit def get_all_entities( self, entity, diff --git a/inventory_provider/db/ims_data.py b/inventory_provider/db/ims_data.py index 371e2f2cfc537d4509bc75d1f8a1222c4493bf9e..81cf11b7e430398537410e29ec27c2e085f871b6 100644 --- a/inventory_provider/db/ims_data.py +++ b/inventory_provider/db/ims_data.py @@ -1,3 +1,4 @@ +import functools import logging import re from collections import defaultdict @@ -9,10 +10,9 @@ from inventory_provider.db import ims from inventory_provider.db.ims import InventoryStatus, IMS, \ CUSTOMER_RELATED_CONTACT_PROPERTIES, EXTRA_FIELD_VALUE_PROPERTIES -environment.setup_logging() logger = logging.getLogger(__name__) - -# Dashboard V3 +log_entry_and_exit = functools.partial( + environment.log_entry_and_exit, logger=logger) IMS_OPSDB_STATUS_MAP = { InventoryStatus.PLANNED: 'planned', @@ -83,6 +83,7 @@ def get_flexils_by_circuitid(ds: IMS): return dict(by_circuit) +@log_entry_and_exit def get_non_monitored_circuit_ids(ds: IMS): # note the id for the relevant field is hard-coded. I didn't want to use # the name of the field as this can be changed by users @@ -94,6 +95,7 @@ def get_non_monitored_circuit_ids(ds: IMS): yield d['extrafieldvalueobjectinfo']['objectid'] +@log_entry_and_exit def get_monitored_circuit_ids(ds: IMS): # note the id for the relevant field is hard-coded. I didn't want to use # the name of the field as this can be changed by users @@ -106,6 +108,7 @@ def get_monitored_circuit_ids(ds: IMS): yield d['extrafieldvalueobjectinfo']['objectid'] +@log_entry_and_exit def get_ids_and_sids(ds: IMS): for sid_circuit in ds.get_filtered_entities( 'ExtraFieldValue', @@ -115,6 +118,7 @@ def get_ids_and_sids(ds: IMS): yield sid_circuit['objectid'], sid_circuit['value'] +@log_entry_and_exit def get_service_types(ds: IMS): for d in ds.get_filtered_entities( 'ComboBoxData', @@ -122,6 +126,7 @@ def get_service_types(ds: IMS): yield d['selection'] +@log_entry_and_exit def get_customer_tts_contacts(ds: IMS): customer_contacts = defaultdict(set) @@ -137,6 +142,7 @@ def get_customer_tts_contacts(ds: IMS): yield k, sorted(list(v)) +@log_entry_and_exit def get_customer_planned_work_contacts(ds: IMS): customer_contacts = defaultdict(set) @@ -152,6 +158,7 @@ def get_customer_planned_work_contacts(ds: IMS): yield k, sorted(list(v)) +@log_entry_and_exit def get_circuit_related_customers(ds: IMS): return_value = defaultdict(list) @@ -169,6 +176,7 @@ def get_circuit_related_customers(ds: IMS): return return_value +@log_entry_and_exit def get_port_id_services(ds: IMS): circuit_nav_props = [ ims.CIRCUIT_PROPERTIES['Ports'], @@ -300,6 +308,7 @@ def get_port_id_services(ds: IMS): } +@log_entry_and_exit def get_port_sids(ds: IMS): """ This function fetches SIDs for external ports that have them defined, @@ -313,6 +322,7 @@ def get_port_sids(ds: IMS): step_count=10000)} +@log_entry_and_exit def get_internal_port_sids(ds: IMS): """ This function fetches SIDs for external ports that have them defined, @@ -326,6 +336,7 @@ def get_internal_port_sids(ds: IMS): step_count=10000)} +@log_entry_and_exit def get_port_details(ds: IMS): port_nav_props = [ ims.PORT_PROPERTIES['Node'], @@ -381,6 +392,7 @@ def get_port_details(ds: IMS): 'internalport', internal_port_nav_props, step_count=2000), 'internal') +@log_entry_and_exit def get_circuit_hierarchy(ds: IMS): circuit_nav_props = [ ims.CIRCUIT_PROPERTIES['Customer'], @@ -425,6 +437,7 @@ def get_circuit_hierarchy(ds: IMS): } +@log_entry_and_exit def get_node_locations(ds: IMS): """ return location info for all Site nodes @@ -498,6 +511,7 @@ INTERNAL_POP_NAMES = { } +@log_entry_and_exit def lookup_lg_routers(ds: IMS): pattern = re.compile("vpn-proxy|vrr|taas", re.IGNORECASE) @@ -562,6 +576,7 @@ def lookup_lg_routers(ds: IMS): yield eq +@log_entry_and_exit def lookup_geant_nodes(ds: IMS): return (n["name"]for n in ds.get_filtered_entities( diff --git a/inventory_provider/environment.py b/inventory_provider/environment.py index 989c0a1355ebb7b0e44f110842b25f045868a47d..ea0c5bff839abe503bf24c6b60d3e79d6c0172f4 100644 --- a/inventory_provider/environment.py +++ b/inventory_provider/environment.py @@ -1,6 +1,24 @@ +import functools import json import logging.config import os +import time + + +def log_entry_and_exit(f, logger): + # cf. https://stackoverflow.com/a/47663642 + # cf. https://stackoverflow.com/a/59098957/6708581 + @functools.wraps(f) + def _w(*args, **kwargs): + logger.debug(f'>>> {f.__name__}{args}') + start_time = time.time() + try: + return f(*args, **kwargs) + finally: + end_time = time.time() + duration = end_time - start_time + logger.debug(f'<<< {f.__name__}{args} -- duration {duration}') + return _w def setup_logging(): diff --git a/inventory_provider/tasks/worker.py b/inventory_provider/tasks/worker.py index 2a58d54adeb272fc831e7c5621f0398091c30131..c6b4ba39b8a4ff13e86642b7db95e626bcc2651d 100644 --- a/inventory_provider/tasks/worker.py +++ b/inventory_provider/tasks/worker.py @@ -4,7 +4,6 @@ import json import logging import os import re -import time from typing import List from celery import Task, states, chord @@ -36,24 +35,9 @@ FINALIZER_TIMEOUT_S = 300 # TODO: error callback (cf. http://docs.celeryproject.org/en/latest/userguide/calling.html#linking-callbacks-errbacks) # noqa: E501 environment.setup_logging() - logger = logging.getLogger(__name__) - - -def log_task_entry_and_exit(f): - # cf. https://stackoverflow.com/a/47663642 - # cf. https://stackoverflow.com/a/59098957/6708581 - @functools.wraps(f) - def _w(*args, **kwargs): - logger.debug(f'>>> {f.__name__}{args}') - start_time = time.time() - try: - return f(*args, **kwargs) - finally: - end_time = time.time() - duration = end_time - start_time - logger.debug(f'<<< {f.__name__}{args} -- duration {duration}') - return _w +log_task_entry_and_exit = functools.partial( + environment.log_entry_and_exit, logger=logger) class InventoryTaskError(Exception):