updating logging format

lemur/common/celery.py

@@ -268,11 +268,14 @@ def clean_all_sources():
     be ran periodically. This function triggers one celery task per source.
     """
     function = f"{__name__}.{sys._getframe().f_code.co_name}"
+    log_data = {
+        "function": function,
+        "message": "Creating celery task to clean source",
+    }
     sources = validate_sources("all")
     for source in sources:
-        current_app.logger.debug(
+        log_data["source"] = source.label
-            "Creating celery task to clean source {}".format(source.label)
+        current_app.logger.debug(log_data)
-        )
         clean_source.delay(source.label)
 
     red.set(f'{function}.last_success', int(time.time()))
@@ -288,7 +291,13 @@ def clean_source(source):
     :param source:
     :return:
     """
-    current_app.logger.debug("Cleaning source {}".format(source))
+    function = f"{__name__}.{sys._getframe().f_code.co_name}"
+    log_data = {
+        "function": function,
+        "message": "Cleaning source",
+        "source": source,
+    }
+    current_app.logger.debug(log_data)
     clean([source], True)
 
 
@@ -298,11 +307,14 @@ def sync_all_sources():
     This function will sync certificates from all sources. This function triggers one celery task per source.
     """
     function = f"{__name__}.{sys._getframe().f_code.co_name}"
+    log_data = {
+        "function": function,
+        "message": "creating celery task to sync source",
+    }
     sources = validate_sources("all")
     for source in sources:
-        current_app.logger.debug(
+        log_data["source"] = source.label
-            "Creating celery task to sync source {}".format(source.label)
+        current_app.logger.debug(log_data)
-        )
         sync_source.delay(source.label)
 
     red.set(f'{function}.last_success', int(time.time()))
@@ -361,14 +373,20 @@ def sync_source_destination():
     The destination sync_as_source_name reveals the name of the suitable source-plugin.
     We rely on account numbers to avoid duplicates.
     """
-    current_app.logger.debug("Syncing AWS destinations and sources")
     function = f"{__name__}.{sys._getframe().f_code.co_name}"
-
+    log_data = {
+        "function": function,
+        "message": "syncing AWS destinations and sources",
+    }
+    current_app.logger.debug(log_data)
     for dst in destinations_service.get_all():
         if add_aws_destination_to_sources(dst):
-            current_app.logger.debug("Source: %s added", dst.label)
+            log_data["message"] = "new source added"
+            log_data["source"] = dst.label
+            current_app.logger.debug(log_data)
 
-    current_app.logger.debug("Completed Syncing AWS destinations and sources")
+    log_data["message"] = "completed Syncing AWS destinations and sources"
+    current_app.logger.debug(log_data)
     red.set(f'{function}.last_success', int(time.time()))
     metrics.send(f"{function}.success", 'counter', 1)
 
@@ -380,9 +398,14 @@ def certificate_reissue():
     :return:
     """
     function = f"{__name__}.{sys._getframe().f_code.co_name}"
-    current_app.logger.debug(f"{function}: reissuing certificates")
+    log_data = {
+        "function": function,
+        "message": "reissuing certificates",
+    }
+    current_app.logger.debug(log_data)
     cli_certificate.reissue(None, True)
-    current_app.logger.debug(f"{function}: reissuance completed")
+    log_data["message"] = "reissuance completed"
+    current_app.logger.debug(log_data)
     red.set(f'{function}.last_success', int(time.time()))
     metrics.send(f"{function}.success", 'counter', 1)
 
@@ -394,9 +417,14 @@ def certificate_rotate():
     :return:
     """
     function = f"{__name__}.{sys._getframe().f_code.co_name}"
-    current_app.logger.debug(f"{function}: rotating certificates")
+    log_data = {
+        "function": function,
+        "message": "rotating certificates",
+    }
+    current_app.logger.debug(log_data)
     cli_certificate.rotate(None, None, None, None, True)
-    current_app.logger.debug(f"{function}: rotation completed")
+    log_data["message"] = "rotation completed"
+    current_app.logger.debug(log_data)
     red.set(f'{function}.last_success', int(time.time()))
     metrics.send(f"{function}.success", 'counter', 1)
 
@@ -408,8 +436,12 @@ def endpoints_expire():
     :return:
     """
     function = f"{__name__}.{sys._getframe().f_code.co_name}"
-    current_app.logger.debug(f"{function}: endpoints expire")
+    log_data = {
-    cli_endpoints.expire(2)
+        "function": function,
+        "message": "endpoints expire",
+    }
+    current_app.logger.debug(log_data)
+    cli_endpoints.expire(2)  # Time in hours
     red.set(f'{function}.last_success', int(time.time()))
     metrics.send(f"{function}.success", 'counter', 1)
 
@@ -421,7 +453,11 @@ def get_all_zones():
     :return:
     """
     function = f"{__name__}.{sys._getframe().f_code.co_name}"
-    current_app.logger.debug(f"{function}: get_all_zones")
+    log_data = {
+        "function": function,
+        "message": "refresh all zones from available DNS providers",
+    }
+    current_app.logger.debug(log_data)
     cli_dns_providers.get_all_zones()
     red.set(f'{function}.last_success', int(time.time()))
     metrics.send(f"{function}.success", 'counter', 1)
@@ -434,7 +470,11 @@ def check_revoked():
     :return:
     """
     function = f"{__name__}.{sys._getframe().f_code.co_name}"
-    current_app.logger.debug(f"{function}: check if any certificates are revoked revoked")
+    log_data = {
+        "function": function,
+        "message": "check if any certificates are revoked revoked",
+    }
+    current_app.logger.debug(log_data)
     cli_certificate.check_revoked()
     red.set(f'{function}.last_success', int(time.time()))
     metrics.send(f"{function}.success", 'counter', 1)
@@ -447,7 +487,11 @@ def notify_expirations():
     :return:
     """
     function = f"{__name__}.{sys._getframe().f_code.co_name}"
-    current_app.logger.debug(f"{function}: Cert Expiration Notifcation")
+    log_data = {
-    cli_notification.expirations(["MetatronUserCertfor", "Metatron-User-Cert-for"])
+        "function": function,
+        "message": "notify for cert expiration",
+    }
+    current_app.logger.debug(log_data)
+    cli_notification.expirations(current_app.config.get("EXCLUDE_CN_FROM_NOTIFICATION", []))
     red.set(f'{function}.last_success', int(time.time()))
     metrics.send(f"{function}.success", 'counter', 1)