Allow the setting of log level by env vars (Azure-Samples#642)

* Allow the setting of log level by env vars Required by Azure-Samples#637 * Allow the setting of log level by env vars Required by Azure-Samples#637 * Add loglevel to env.sample * Allow log level to be set via bicep * Set log level in admin app * Correctly configure logs in web app * Ensure log level is set for functions * Remove duplicated tests * Fix main.json after merge * Reduce verbose azure logs
devopsdale · Apr 11, 2024 · f1c7db6 · f1c7db6
1 parent d78b593
commit f1c7db6
Show file tree

Hide file tree

Showing 17 changed files with 89 additions and 26 deletions.
diff --git a/.env.sample b/.env.sample
@@ -55,3 +55,4 @@ AZURE_SPEECH_SERVICE_REGION=
 AZURE_AUTH_TYPE=keys
 USE_KEY_VAULT=true
 AZURE_KEY_VAULT_ENDPOINT=
+LOGLEVEL=INFO
diff --git a/code/app.py b/code/app.py
@@ -1,7 +1,11 @@
 import os
+import logging
 from azure.monitor.opentelemetry import configure_azure_monitor
 from opentelemetry.instrumentation.httpx import HTTPXClientInstrumentor
 
+logging.basicConfig(level=os.environ.get("LOGLEVEL", "INFO").upper())
+# Raising the azure log level to WARN as it is too verbose - https://github.com/Azure/azure-sdk-for-python/issues/9422
+logging.getLogger("azure").setLevel(os.environ.get("LOGLEVEL_AZURE", "WARN").upper())
 # We cannot use EnvHelper here as Application Insights should be configured first
 # for instrumentation to work correctly
 if os.getenv("APPINSIGHTS_ENABLED", "false").lower() == "true":

diff --git a/code/backend/Admin.py b/code/backend/Admin.py
@@ -10,14 +10,16 @@
 
 sys.path.append(os.path.join(os.path.dirname(__file__), ".."))
 
+logging.basicConfig(level=os.getenv("LOGLEVEL", "INFO").upper())
+# Raising the azure log level to WARN as it is too verbose - https://github.com/Azure/azure-sdk-for-python/issues/9422
+logging.getLogger("azure").setLevel(os.environ.get("LOGLEVEL_AZURE", "WARN").upper())
 # We cannot use EnvHelper here as Application Insights needs to be configured first
 # for instrumentation to work correctly
 if os.getenv("APPINSIGHTS_ENABLED", "false").lower() == "true":
     configure_azure_monitor()
 
-logger = logging.getLogger("azure.core.pipeline.policies.http_logging_policy").setLevel(
-    logging.WARNING
-)
+logger = logging.getLogger(__name__)
+logger.debug("Starting admin app")
 
 
 st.set_page_config(

diff --git a/code/backend/batch/AddURLEmbeddings.py b/code/backend/batch/AddURLEmbeddings.py
@@ -3,14 +3,17 @@
 import azure.functions as func
 import sys
 
+from utilities.helpers.EnvHelper import EnvHelper
 from utilities.helpers.DocumentProcessorHelper import DocumentProcessor
 from utilities.helpers.ConfigHelper import ConfigHelper
 
 sys.path.append("..")
 
 bp_add_url_embeddings = func.Blueprint()
+env_helper: EnvHelper = EnvHelper()
 
 logger = logging.getLogger(__name__)
+logger.setLevel(env_helper.LOGLEVEL)
 
 
 @bp_add_url_embeddings.route(route="AddURLEmbeddings")

diff --git a/code/backend/batch/BatchPushResults.py b/code/backend/batch/BatchPushResults.py
@@ -4,15 +4,18 @@
 from urllib.parse import urlparse
 import sys
 
+from utilities.helpers.EnvHelper import EnvHelper
 from utilities.helpers.AzureBlobStorageHelper import AzureBlobStorageClient
 from utilities.helpers.DocumentProcessorHelper import DocumentProcessor
 from utilities.helpers.ConfigHelper import ConfigHelper
 
 sys.path.append("..")
 
 bp_batch_push_results = func.Blueprint()
+env_helper: EnvHelper = EnvHelper()
 
 logger = logging.getLogger(__name__)
+logger.setLevel(env_helper.LOGLEVEL)
 
 
 def _get_file_name_from_message(msg: func.QueueMessage) -> str:

diff --git a/code/backend/batch/BatchStartProcessing.py b/code/backend/batch/BatchStartProcessing.py
@@ -13,6 +13,7 @@
 env_helper: EnvHelper = EnvHelper()
 
 logger = logging.getLogger(__name__)
+logger.setLevel(env_helper.LOGLEVEL)
 
 
 @bp_batch_start_processing.route(route="BatchStartProcessing")

diff --git a/code/backend/batch/GetConversationResponse.py b/code/backend/batch/GetConversationResponse.py
@@ -11,6 +11,7 @@
 env_helper: EnvHelper = EnvHelper()
 
 logger = logging.getLogger(__name__)
+logger.setLevel(env_helper.LOGLEVEL)
 
 
 @bp_get_conversation_response.route(route="GetConversationResponse")

diff --git a/code/backend/batch/function_app.py b/code/backend/batch/function_app.py
@@ -1,10 +1,14 @@
+import logging
+import os
 import azure.functions as func
 from AddURLEmbeddings import bp_add_url_embeddings
 from BatchPushResults import bp_batch_push_results
 from BatchStartProcessing import bp_batch_start_processing
 from GetConversationResponse import bp_get_conversation_response
 from azure.monitor.opentelemetry import configure_azure_monitor
 
+# Raising the azure log level to WARN as it is too verbose - https://github.com/Azure/azure-sdk-for-python/issues/9422
+logging.getLogger("azure").setLevel(os.environ.get("LOGLEVEL_AZURE", "WARN").upper())
 configure_azure_monitor()
 
 app = func.FunctionApp(

diff --git a/code/backend/batch/utilities/helpers/EnvHelper.py b/code/backend/batch/utilities/helpers/EnvHelper.py
@@ -14,6 +14,8 @@ def __init__(self, **kwargs) -> None:
         # Wrapper for Azure Key Vault
         self.secretHelper = SecretHelper()
 
+        self.LOGLEVEL = os.environ.get("LOGLEVEL", "INFO").upper()
+
         # Azure Search
         self.AZURE_SEARCH_SERVICE = os.getenv("AZURE_SEARCH_SERVICE", "")
         self.AZURE_SEARCH_INDEX = os.getenv("AZURE_SEARCH_INDEX", "")

diff --git a/code/backend/pages/01_Ingest_Data.py b/code/backend/pages/01_Ingest_Data.py
@@ -5,7 +5,6 @@
 import traceback
 import chardet
 from datetime import datetime, timedelta
-import logging
 import requests
 from azure.identity import DefaultAzureCredential
 from azure.storage.blob import (
@@ -22,9 +21,6 @@
 sys.path.append(path.join(path.dirname(__file__), ".."))
 env_helper: EnvHelper = EnvHelper()
 
-logger = logging.getLogger("azure.core.pipeline.policies.http_logging_policy").setLevel(
-    logging.WARNING
-)
 st.set_page_config(
     page_title="Ingest Data",
     page_icon=path.join("images", "favicon.ico"),

diff --git a/code/backend/pages/02_Explore_Data.py b/code/backend/pages/02_Explore_Data.py
@@ -2,7 +2,6 @@
 import os
 import json
 import traceback
-import logging
 import pandas as pd
 import sys
 from batch.utilities.helpers.AzureSearchHelper import AzureSearchHelper
@@ -12,9 +11,6 @@
 
 load_dotenv()
 
-logger = logging.getLogger("azure.core.pipeline.policies.http_logging_policy").setLevel(
-    logging.WARNING
-)
 st.set_page_config(
     page_title="Explore Data",
     page_icon=os.path.join("images", "favicon.ico"),

diff --git a/code/backend/pages/03_Delete_Data.py b/code/backend/pages/03_Delete_Data.py
@@ -1,7 +1,6 @@
 import streamlit as st
 import os
 import traceback
-import logging
 import sys
 from batch.utilities.helpers.AzureSearchHelper import AzureSearchHelper
 from dotenv import load_dotenv
@@ -10,9 +9,6 @@
 
 load_dotenv()
 
-logger = logging.getLogger("azure.core.pipeline.policies.http_logging_policy").setLevel(
-    logging.WARNING
-)
 st.set_page_config(
     page_title="Delete Data",
     page_icon=os.path.join("images", "favicon.ico"),

diff --git a/code/backend/pages/04_Configuration.py b/code/backend/pages/04_Configuration.py
@@ -1,7 +1,6 @@
 import streamlit as st
 import os
 import traceback
-import logging
 from dotenv import load_dotenv
 import sys
 from batch.utilities.helpers.ConfigHelper import ConfigHelper
@@ -10,9 +9,6 @@
 
 load_dotenv()
 
-logger = logging.getLogger("azure.core.pipeline.policies.http_logging_policy").setLevel(
-    logging.WARNING
-)
 st.set_page_config(
     page_title="Configure Prompts",
     page_icon=os.path.join("images", "favicon.ico"),

diff --git a/code/create_app.py b/code/create_app.py
@@ -298,6 +298,8 @@ def create_app():
     app = Flask(__name__)
     env_helper: EnvHelper = EnvHelper()
 
+    logger.debug("Starting web app")
+
     @app.route("/", defaults={"path": "index.html"})
     @app.route("/<path:path>")
     def static_file(path):

diff --git a/code/tests/utilities/test_EnvHelper.py b/code/tests/utilities/test_EnvHelper.py
@@ -72,3 +72,22 @@ def test_keys_are_unset_when_auth_type_rbac(monkeypatch: MonkeyPatch):
     assert env_helper.AZURE_SEARCH_KEY is None
     assert env_helper.AZURE_OPENAI_API_KEY == ""
     assert env_helper.AZURE_SPEECH_KEY is None
+
+
+def test_sets_default_log_level_when_unset():
+    # when
+    env_helper = EnvHelper()
+
+    # then
+    assert env_helper.LOGLEVEL == "INFO"
+
+
+def test_uses_and_uppercases_log_level_when_set(monkeypatch: MonkeyPatch):
+    # given
+    monkeypatch.setenv("LOGLEVEL", "deBug")
+
+    # when
+    env_helper = EnvHelper()
+
+    # then
+    assert env_helper.LOGLEVEL == "DEBUG"
diff --git a/infra/main.bicep b/infra/main.bicep
@@ -177,6 +177,15 @@ param authType string = 'keys'
 ])
 param hostingModel string = 'container'
 
+@allowed([
+  'CRITICAL'
+  'ERROR'
+  'WARN'
+  'INFO'
+  'DEBUG'
+])
+param logLevel string = 'INFO'
+
 var blobContainerName = 'documents'
 var queueName = 'doc-processing'
 var clientKey = '${uniqueString(guid(subscription().id, deployment().name))}${newGuidString}'
@@ -382,6 +391,7 @@ module web './app/web.bicep' = if (hostingModel == 'code') {
       AZURE_SPEECH_SERVICE_NAME: speechServiceName
       AZURE_SPEECH_SERVICE_REGION: location
       ORCHESTRATION_STRATEGY: orchestrationStrategy
+      LOGLEVEL: logLevel
     }
   }
 }
@@ -442,6 +452,7 @@ module web_docker './app/web.bicep' = if (hostingModel == 'container') {
       AZURE_SPEECH_SERVICE_NAME: speechServiceName
       AZURE_SPEECH_SERVICE_REGION: location
       ORCHESTRATION_STRATEGY: orchestrationStrategy
+      LOGLEVEL: logLevel
     }
   }
 }
@@ -503,6 +514,7 @@ module adminweb './app/adminweb.bicep' = if (hostingModel == 'code') {
       DOCUMENT_PROCESSING_QUEUE_NAME: queueName
       FUNCTION_KEY: clientKey
       ORCHESTRATION_STRATEGY: orchestrationStrategy
+      LOGLEVEL: logLevel
     }
   }
 }
@@ -563,6 +575,7 @@ module adminweb_docker './app/adminweb.bicep' = if (hostingModel == 'container')
       DOCUMENT_PROCESSING_QUEUE_NAME: queueName
       FUNCTION_KEY: clientKey
       ORCHESTRATION_STRATEGY: orchestrationStrategy
+      LOGLEVEL: logLevel
     }
   }
 }
@@ -639,6 +652,7 @@ module function './app/function.bicep' = if (hostingModel == 'code') {
       AZURE_SEARCH_SERVICE: 'https://${azureAISearchName}.search.windows.net'
       DOCUMENT_PROCESSING_QUEUE_NAME: queueName
       ORCHESTRATION_STRATEGY: orchestrationStrategy
+      LOGLEVEL: logLevel
     }
   }
 }
@@ -682,6 +696,7 @@ module function_docker './app/function.bicep' = if (hostingModel == 'container')
       AZURE_SEARCH_SERVICE: 'https://${azureAISearchName}.search.windows.net'
       DOCUMENT_PROCESSING_QUEUE_NAME: queueName
       ORCHESTRATION_STRATEGY: orchestrationStrategy
+      LOGLEVEL: logLevel
     }
   }
 }
@@ -843,3 +858,4 @@ output USE_KEY_VAULT bool = useKeyVault
 output AZURE_APP_SERVICE_HOSTING_MODEL string = hostingModel
 output FRONTEND_WEBSITE_NAME string = hostingModel == 'code' ? web.outputs.FRONTEND_API_URI : web_docker.outputs.FRONTEND_API_URI
 output ADMIN_WEBSITE_NAME string = hostingModel == 'code' ? adminweb.outputs.WEBSITE_ADMIN_URI : adminweb_docker.outputs.WEBSITE_ADMIN_URI
+output LOGLEVEL string = logLevel
diff --git a/infra/main.json b/infra/main.json
@@ -5,7 +5,7 @@
     "_generator": {
       "name": "bicep",
       "version": "0.26.54.24096",
-      "templateHash": "7715045314239280418"
+      "templateHash": "15295378206128435887"
     }
   },
   "parameters": {
@@ -372,6 +372,17 @@
       "metadata": {
         "description": "Hosting model for the web apps. Containers are prebuilt and can be deployed faster, but code allows for more customization."
       }
+    },
+    "logLevel": {
+      "type": "string",
+      "defaultValue": "INFO",
+      "allowedValues": [
+        "CRITICAL",
+        "ERROR",
+        "WARN",
+        "INFO",
+        "DEBUG"
+      ]
     }
   },
   "variables": {
@@ -1506,7 +1517,8 @@
               "AZURE_SEARCH_URL_COLUMN": "[parameters('azureSearchUrlColumn')]",
               "AZURE_SPEECH_SERVICE_NAME": "[parameters('speechServiceName')]",
               "AZURE_SPEECH_SERVICE_REGION": "[parameters('location')]",
-              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]"
+              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]",
+              "LOGLEVEL": "[parameters('logLevel')]"
             }
           }
         },
@@ -2359,7 +2371,8 @@
               "AZURE_SEARCH_URL_COLUMN": "[parameters('azureSearchUrlColumn')]",
               "AZURE_SPEECH_SERVICE_NAME": "[parameters('speechServiceName')]",
               "AZURE_SPEECH_SERVICE_REGION": "[parameters('location')]",
-              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]"
+              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]",
+              "LOGLEVEL": "[parameters('logLevel')]"
             }
           }
         },
@@ -3215,7 +3228,8 @@
               "BACKEND_URL": "[format('https://{0}.azurewebsites.net', parameters('functionName'))]",
               "DOCUMENT_PROCESSING_QUEUE_NAME": "[variables('queueName')]",
               "FUNCTION_KEY": "[variables('clientKey')]",
-              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]"
+              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]",
+              "LOGLEVEL": "[parameters('logLevel')]"
             }
           }
         },
@@ -4137,7 +4151,8 @@
               "BACKEND_URL": "[format('https://{0}-docker.azurewebsites.net', parameters('functionName'))]",
               "DOCUMENT_PROCESSING_QUEUE_NAME": "[variables('queueName')]",
               "FUNCTION_KEY": "[variables('clientKey')]",
-              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]"
+              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]",
+              "LOGLEVEL": "[parameters('logLevel')]"
             }
           }
         },
@@ -6780,7 +6795,8 @@
               "AZURE_SEARCH_INDEX": "[parameters('azureSearchIndex')]",
               "AZURE_SEARCH_SERVICE": "[format('https://{0}.search.windows.net', parameters('azureAISearchName'))]",
               "DOCUMENT_PROCESSING_QUEUE_NAME": "[variables('queueName')]",
-              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]"
+              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]",
+              "LOGLEVEL": "[parameters('logLevel')]"
             }
           }
         },
@@ -7996,7 +8012,8 @@
               "AZURE_SEARCH_INDEX": "[parameters('azureSearchIndex')]",
               "AZURE_SEARCH_SERVICE": "[format('https://{0}.search.windows.net', parameters('azureAISearchName'))]",
               "DOCUMENT_PROCESSING_QUEUE_NAME": "[variables('queueName')]",
-              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]"
+              "ORCHESTRATION_STRATEGY": "[parameters('orchestrationStrategy')]",
+              "LOGLEVEL": "[parameters('logLevel')]"
             }
           }
         },
@@ -10261,6 +10278,10 @@
     "ADMIN_WEBSITE_NAME": {
       "type": "string",
       "value": "[if(equals(parameters('hostingModel'), 'code'), reference(extensionResourceId(format('/subscriptions/{0}/resourceGroups/{1}', subscription().subscriptionId, variables('rgName')), 'Microsoft.Resources/deployments', parameters('adminWebsiteName')), '2022-09-01').outputs.WEBSITE_ADMIN_URI.value, reference(extensionResourceId(format('/subscriptions/{0}/resourceGroups/{1}', subscription().subscriptionId, variables('rgName')), 'Microsoft.Resources/deployments', format('{0}-docker', parameters('adminWebsiteName'))), '2022-09-01').outputs.WEBSITE_ADMIN_URI.value)]"
+    },
+    "LOGLEVEL": {
+      "type": "string",
+      "value": "[parameters('logLevel')]"
     }
   }
 }