add logging handler once for controller app

controller_function/controller/__init__.py

@@ -8,7 +8,7 @@
 
 from controller import models, settings
 from controller.auth import BearerAuth
-from controller.logutils import set_log_handler
+from controller.logutils import add_log_handler_once
 from controller.subscription import disable_subscription, enable_subscription
 
 logger = logging.getLogger(__name__)
@@ -86,7 +86,7 @@ def main(mytimer: func.TimerRequest) -> None:
         format="%(asctime)s %(message)s",
         datefmt="%d/%m/%Y %I:%M:%S %p",
     )
-    set_log_handler(__name__)
+    add_log_handler_once(__name__)
 
     logger.warning("Controller function starting.")
 

controller_function/controller/logutils.py

@@ -24,7 +24,7 @@ def filter(self, record: logging.LogRecord) -> bool:
         return True
 
 
-def set_log_handler(name: str = "controller") -> None:
+def add_log_handler_once(name: str = "controller") -> None:
     """Add an Azure log handler to the logger with provided name.
 
     The log data is sent to the Azure Application Insights instance associated
@@ -38,6 +38,11 @@ def set_log_handler(name: str = "controller") -> None:
     logger = logging.getLogger(name)
     log_settings = settings.get_settings()
     if log_settings.CENTRAL_LOGGING_CONNECTION_STRING:
+        for handler in logger.handlers:
+            # Only allow one AzureLogHandler per logger
+            if isinstance(handler, AzureLogHandler):
+                return
+
         custom_dimensions = {"logger_name": f"logger_{name}"}
         handler = AzureLogHandler(
             connection_string=log_settings.CENTRAL_LOGGING_CONNECTION_STRING

controller_function/run_tests.sh

@@ -30,10 +30,10 @@ status=$((status+$?))
 
 # Run our unit tests with code coverage
 echo "Running unit tests..."
-# shellcheck disable=SC2140
-python -m \
-  coverage run --omit=".venv/*","tests/*" -m \
-  unittest discover --start-directory=tests/
+python -m coverage run \
+  --omit=".venv/*,tests/*" \
+  -m unittest discover \
+  --start-directory=tests/
 status=$((status+$?))
 
 # Show the lines our tests miss

controller_function/tests/test_function_app.py

@@ -1,5 +1,6 @@
 """Tests for controller package."""
 import json
+import logging
 from unittest import TestCase, main
 from unittest.mock import MagicMock, call, patch
 from uuid import UUID
@@ -185,5 +186,18 @@ def test_bearer_auth(self):
             self.assertEqual("controller-app", username)
 
 
+class TestLoggingUtils(TestCase):
+    def test_called_twice(self):
+        """Adding multiple loggers could cause large storage bills."""
+        with patch("controller.settings.get_settings") as mock_get_settings:
+            mock_get_settings.return_value.CENTRAL_LOGGING_CONNECTION_STRING = "my-str"
+
+            with patch("controller.logutils.AzureLogHandler", new=MagicMock):
+                controller.logutils.add_log_handler_once("a")
+                controller.logutils.add_log_handler_once("a")
+        handlers = logging.getLogger("a").handlers
+        self.assertEqual(1, len(handlers))
+
+
 if __name__ == "__main__":
     main()