Feature/more logging #57 (#64)

* Log level as env var and status logging in main loop

* Adding additional debug logging

src/hutch_bunny/core/execute_query.py

@@ -31,6 +31,7 @@ def execute_query(
     logger.info("Processing query...")
 
     if "analysis" in query_dict.keys():
+        logger.debug("Processing distribution query...")
         try:
             query = DistributionQuery.from_dict(query_dict)
             result = query_solvers.solve_distribution(
@@ -45,6 +46,7 @@ def execute_query(
             logger.error(str(ve), exc_info=True)
 
     else:
+        logger.debug("Processing availability query...")
         try:
             query = AvailabilityQuery.from_dict(query_dict)
             result = query_solvers.solve_availability(

src/hutch_bunny/core/settings.py

@@ -48,3 +48,25 @@
     POLLING_INTERVAL = POLLING_INTERVAL_DEFAULT
 
 COLLECTION_ID = environ.get("COLLECTION_ID")
+
+def log_settings():
+    from hutch_bunny.core.logger import logger #This is here to prevent a circular import
+
+    logger.debug("Running with settings:")
+    logger.debug(f"  DATASOURCE_USE_TRINO: {DATASOURCE_USE_TRINO}")
+    logger.debug(f"  DEFAULT_POSTGRES_DRIVER: {DEFAULT_POSTGRES_DRIVER}")
+    logger.debug(f"  DEFAULT_DB_DRIVER: {DEFAULT_DB_DRIVER}")
+    logger.debug(f"  LOGGER_NAME: {LOGGER_NAME}")
+    logger.debug(f"  LOGGER_LEVEL: {LOGGER_LEVEL}")
+    logger.debug(f"  BACKUP_LOGGER_NAME: {BACKUP_LOGGER_NAME}")
+    logger.debug(f"  MSG_FORMAT: {MSG_FORMAT}")
+    logger.debug(f"  DATE_FORMAT: {DATE_FORMAT}")
+    logger.debug(f"  TASK_API_BASE_URL: {TASK_API_BASE_URL}")
+    logger.debug(f"  TASK_API_USERNAME: {TASK_API_USERNAME}")
+    logger.debug(f"  TASK_API_PASSWORD: {TASK_API_PASSWORD}")
+    logger.debug(f"  TASK_API_TYPE: {TASK_API_TYPE}")
+    logger.debug(f"  LOW_NUMBER_SUPPRESSION_THRESHOLD: {LOW_NUMBER_SUPPRESSION_THRESHOLD}")
+    logger.debug(f"  ROUNDING_TARGET: {ROUNDING_TARGET}")
+    logger.debug(f"  POLLING_INTERVAL_DEFAULT: {POLLING_INTERVAL_DEFAULT}")
+    logger.debug(f"  POLLING_INTERVAL: {POLLING_INTERVAL}")
+    logger.debug(f"  COLLECTION_ID: {COLLECTION_ID}")

src/hutch_bunny/core/task_api_client.py

@@ -4,6 +4,7 @@
 from requests.auth import HTTPBasicAuth
 import hutch_bunny.core.settings as settings
 from typing import Optional
+from hutch_bunny.core.logger import logger
 
 
 class SupportedMethod(Enum):
@@ -40,10 +41,13 @@ def request(
         Returns:
             Response: The response object returned by the requests library.
         """
+        logger.debug("Sending %s request to %s with data %s and kwargs %s" % (method.value, url,data, kwargs))
         basicAuth = HTTPBasicAuth(self.username, self.password)
         response = requests.request(
             method=method.value, url=url, json=data, auth=basicAuth, **kwargs
         )
+        logger.debug("Response Status: %s", response.status_code)
+        logger.debug("Response Text: %s", response.text)
         return response
 
     def post(

src/hutch_bunny/daemon.py

@@ -8,6 +8,7 @@
 from hutch_bunny.core.setting_database import setting_database
 
 def main() -> None:
+    settings.log_settings()
     # Setting database connection
     db_manager = setting_database(logger=logger)
     # Task Api Client class init.
@@ -29,6 +30,7 @@ def main() -> None:
         response = client.get(endpoint=polling_endpoint)
         if response.status_code == 200:
             logger.info("Job received. Resolving...")
+            logger.debug("JSON Response: %s", response.json())
             # Convert Response to Dict
             query_dict: dict = response.json()
             # Start querying
@@ -44,7 +46,7 @@ def main() -> None:
 
             # Build return endpoint after having result
             return_endpoint = f"task/result/{result.uuid}/{result.collection_id}"
-
+            logger.debug("Return endpoint: %s", return_endpoint)
             # Try to send the results back to Relay
             for _ in range(4):
                 response = client.post(endpoint=return_endpoint, data=result.to_dict())
@@ -55,6 +57,8 @@ def main() -> None:
                     or 400 <= response.status_code < 500
                 ):
                     logger.info("Job resolved.")
+                    logger.debug("Response status: %s", response.status_code)
+                    logger.debug("Response: %s", response.text)
                     break
                 else:
                     logger.warning(