decorator to handle entry/exit logging

inventory_provider/tasks/worker.py

@@ -30,6 +30,15 @@ environment.setup_logging()
 logger = logging.getLogger(__name__)
 
 
+def log_entry_and_exit(f):
+    def _w(*args, **kwargs):
+        logger.debug(f'>>> {f.__name__}{args}')
+        try:
+            return f(*args, *kwargs)
+        finally:
+            logger.debug(f'<<< {f.__name__}{args}')
+    return _w
+
 class InventoryTaskError(Exception):
     pass
 
@@ -67,36 +76,25 @@ class InventoryTask(Task):
 
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def snmp_refresh_interfaces(self, hostname, community):
-    logger.debug(
-        '>>> snmp_refresh_interfaces(%r, %r)' % (hostname, community))
-
     value = list(snmp.get_router_snmp_indexes(hostname, community))
-
     r = get_next_redis(InventoryTask.config)
     r.set('snmp-interfaces:' + hostname, json.dumps(value))
 
-    logger.debug(
-        '<<< snmp_refresh_interfaces(%r, %r)' % (hostname, community))
-
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def netconf_refresh_config(self, hostname):
-    logger.debug('>>> netconf_refresh_config(%r)' % hostname)
-
     netconf_doc = juniper.load_config(hostname, InventoryTask.config["ssh"])
     netconf_str = etree.tostring(netconf_doc, encoding='unicode')
-
     r = get_next_redis(InventoryTask.config)
     r.set('netconf:' + hostname, netconf_str)
 
-    logger.debug('<<< netconf_refresh_config(%r)' % hostname)
-
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def update_interfaces_to_services(self):
-    logger.debug('>>> update_interfaces_to_services')
-
     interface_services = defaultdict(list)
     with db.connection(InventoryTask.config["ops-db"]) as cx:
         for service in opsdb.get_circuits(cx):
@@ -117,12 +115,10 @@ def update_interfaces_to_services(self):
             json.dumps(services))
     rp.execute()
 
-    logger.debug('<<< update_interfaces_to_services')
-
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def import_unmanaged_interfaces(self):
-    logger.debug('>>> import_unmanaged_interfaces')
 
     def _convert(d):
         # the config file keys are more readable than
@@ -151,12 +147,10 @@ def import_unmanaged_interfaces(self):
                 json.dumps([ifc]))
         rp.execute()
 
-    logger.debug('<<< import_unmanaged_interfaces')
-
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def update_access_services(self):
-    logger.debug('>>> update_access_services')
 
     access_services = {}
     with db.connection(InventoryTask.config["ops-db"]) as cx:
@@ -182,12 +176,10 @@ def update_access_services(self):
             json.dumps(service))
     rp.execute()
 
-    logger.debug('<<< update_access_services')
-
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def update_lg_routers(self):
-    logger.debug('>>> update_lg_routers')
 
     r = get_next_redis(InventoryTask.config)
     rp = r.pipeline()
@@ -201,13 +193,10 @@ def update_lg_routers(self):
             rp.set(f'opsdb:lg:{router["equipment name"]}', json.dumps(router))
         rp.execute()
 
-    logger.debug('<<< update_lg_routers')
-
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def update_equipment_locations(self):
-    logger.debug('>>> update_equipment_locations')
-
     r = get_next_redis(InventoryTask.config)
     rp = r.pipeline()
     for k in r.scan_iter('opsdb:location:*'):
@@ -223,12 +212,10 @@ def update_equipment_locations(self):
             rp.set('opsdb:location:%s' % h, json.dumps(locations))
         rp.execute()
 
-    logger.debug('<<< update_equipment_locations')
-
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def update_circuit_hierarchy(self):
-    logger.debug('>>> update_circuit_hierarchy')
 
     # TODO: integers are not JSON keys
     with db.connection(InventoryTask.config["ops-db"]) as cx:
@@ -255,12 +242,10 @@ def update_circuit_hierarchy(self):
             rp.set('opsdb:services:children:%d' % cid, json.dumps(children))
         rp.execute()
 
-    logger.debug('<<< update_circuit_hierarchy')
-
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def update_geant_lambdas(self):
-    logger.debug('>>> update_geant_lambdas')
 
     r = get_next_redis(InventoryTask.config)
     rp = r.pipeline()
@@ -276,13 +261,10 @@ def update_geant_lambdas(self):
                 json.dumps(ld))
         rp.execute()
 
-    logger.debug('<<< geant_lambdas')
-
 
 @app.task(base=InventoryTask, bind=True)
-def update_junosspace_device_list(self):
-    logger.debug('>>> update_junosspace_device_list')
-
+@log_entry_and_exit
+def update_neteng_managed_device_list(self):
     self.update_state(
         state=states.STARTED,
         meta={
@@ -314,8 +296,6 @@ def update_junosspace_device_list(self):
         rp.set(k, v)
     rp.execute()
 
-    logger.debug('<<< update_junosspace_device_list')
-
     return {
         'task': 'update_junosspace_device_list',
         'message': 'saved %d managed routers' % len(routers)
@@ -448,9 +428,8 @@ def refresh_juniper_interface_list(hostname, netconf):
 
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def reload_router_config(self, hostname):
-    logger.debug('>>> reload_router_config')
-
     self.update_state(
         state=states.STARTED,
         meta={
@@ -520,8 +499,6 @@ def reload_router_config(self, hostname):
 
     clear_cached_classifier_responses(None)
 
-    logger.debug('<<< reload_router_config')
-
     return {
         'task': 'reload_router_config',
         'hostname': hostname,
@@ -559,7 +536,7 @@ def launch_refresh_cache_all(config):
 
     # first batch of subtasks: refresh cached opsdb data
     subtasks = [
-        update_junosspace_device_list.apply_async(),
+        update_neteng_managed_device_list.apply_async(),
         update_interfaces_to_services.apply_async(),
         update_geant_lambdas.apply_async(),
         update_circuit_hierarchy.apply_async()
@@ -619,9 +596,8 @@ def _wait_for_tasks(task_ids, update_callback=lambda s: None):
 
 
 @app.task(base=InventoryTask, bind=True)
+@log_entry_and_exit
 def refresh_finalizer(self, pending_task_ids_json):
-    logger.debug('>>> refresh_finalizer')
-    logger.debug('task_ids: %r' % pending_task_ids_json)
 
     input_schema = {
         "$schema": "http://json-schema.org/draft-07/schema#",
@@ -656,11 +632,9 @@ def refresh_finalizer(self, pending_task_ids_json):
     latch_db(InventoryTask.config)
     _update('latched current/next dbs')
 
-    logger.debug('<<< refresh_finalizer')
-
 
+@log_entry_and_exit
 def _build_service_category_interface_list(update_callback=lambda s: None):
-    logger.debug('>>> _build_interface_services')
 
     def _classify(ifc):
         if ifc['description'].startswith('SRV_MDVPN'):
@@ -688,7 +662,6 @@ def _build_service_category_interface_list(update_callback=lambda s: None):
             json.dumps(ifc))
 
     rp.execute()
-    logger.debug('<<< _build_interface_services')
 
 
 def _build_subnet_db(update_callback=lambda s: None):