feat/log commands to file (#165)

* feat(logging): log commands to file to facilitate debugging

* feat(cli execution): add both print and logs

* chore(gitignore): add odtp.log to gitignore

* fix(run.py): don't log secrets to file

---------

Co-authored-by: sabinem <5292683+sabinem@users.noreply.github.com>

.gitignore

@@ -4,3 +4,4 @@ __pycache__/
 !.env*.dist
 .nicegui
 .local
+odtp/odtp.log

odtp/cli/execution.py

@@ -47,10 +47,14 @@ def prepare(
         flowManager = WorkflowManager(execution, project_path, secrets)
         flowManager.prepare_workflow()
     except Exception as e:
-        log.error(f"ERROR: Prepare execution failed: {e}") 
+        msg = f"ERROR: Prepare execution failed: {e}"
+        log.exception(msg) 
+        print(msg)
         raise typer.Abort()           
     else:
-        log.info("SUCCESS: images for the execution have been build")    
+        msg = "SUCCESS: images for the execution have been build"
+        log.info(msg)
+        print(msg)
 
 
 @app.command()
@@ -85,10 +89,14 @@ def run(
         flowManager = WorkflowManager(execution, project_path, secrets)
         flowManager.run_workflow()
     except Exception as e:
-        log.error(f"ERROR: Prepare execution failed: {e}")       
+        msg = f"ERROR: Prepare execution failed: {e}"
+        log.exception(msg)
+        print(msg)     
         raise typer.Abort()
     else:
-        log.info("SUCCESS: containers for the execution have been run")      
+        msg = "SUCCESS: containers for the execution have been run"
+        log.info(msg)
+        print(msg)
 
 
 @app.command()

odtp/dashboard/page_run/run.py

@@ -5,10 +5,13 @@
 import sys
 
 from nicegui import ui
+import odtp.helpers.settings as config
 import odtp.dashboard.page_run.helpers as rh
 import odtp.dashboard.page_run.folder as folder
 
 log = logging.getLogger(__name__)
+log.setLevel(logging.INFO)
+log.addHandler(config.get_command_log_handler())
 
 
 def ui_prepare_execution(dialog, result, current_run, folder_status):

odtp/helpers/settings.py

@@ -5,6 +5,7 @@
 load_dotenv()
 
 logger = logging.getLogger(__name__)
+code_file_dir = os.path.abspath(__file__)
 
 DEFAULT_LOG_LEVEL = "ERROR"
 DEFAULT_RUN_LOG_LEVEL = "INFO"
@@ -49,3 +50,12 @@ class OdtpSettingsException(Exception):
 log_levels = logging.getLevelNamesMapping()
 if not RUN_LOG_LEVEL in log_levels.keys():
     RUN_LOG_LEVEL = DEFAULT_RUN_LOG_LEVEL
+
+def get_command_log_handler():
+    log_file_path = os.path.join(os.path.dirname(os.path.dirname(code_file_dir)), 'odtp.log')
+    command_log_handler = logging.FileHandler(log_file_path)
+    FORMATTER = logging.Formatter(
+        '%(asctime)s - [%(module)s:%(levelname)s] %(lineno)d %(filename)s %(funcName)s - %(message)s'
+    )
+    command_log_handler.setFormatter(FORMATTER)
+    return command_log_handler

odtp/run.py

@@ -17,7 +17,8 @@
 
 
 log = logging.getLogger(__name__)
-log.setLevel(logging.DEBUG)
+log.setLevel(logging.INFO)
+log.addHandler(config.get_command_log_handler())
 
 
 class OdtpRunSetupException(Exception):
@@ -77,7 +78,7 @@ def _checks_for_prepare(self):
         )
 
     def _checks_for_run(self, parameters, ports, image_name):
-        log.info("VALIDATION: check for run") 
+        log.info("VALIDATION: check for run")
         self._check_project_folder_prepared()
         self._check_image_exists()
         try:
@@ -168,7 +169,7 @@ def _create_volume(self, volume_name):
         log.info(f"RUN: Creating Docker volume {volume_name}")
         subprocess.run(["docker", "volume", "create", volume_name])
 
-    def run_component(self, parameters, secrets, ports, container_name, step_id=None, debug=False):
+    def run_component(self, parameters, secrets, ports, container_name, step_id=None):
         """
         Run a Docker component with the specified parameters.
 
@@ -209,9 +210,14 @@ def run_component(self, parameters, secrets, ports, container_name, step_id=None
                               "--volume", f"{os.path.abspath(self.output_volume)}:/odtp/odtp-output"] + env_args + ports_args + secrets_args + [self.docker_image_name]
 
         command_string = ' '.join(docker_run_command)
-        if debug:
-            log.debug(f"Command to be executed: {command_string}")
+        command_string_log_safe = command_string
+        for value in [parameters["ODTP_SECRET_KEY"], parameters["ODTP_ACCESS_KEY"], parameters["ODTP_MONGO_SERVER"]]:
+            command_string_log_safe = command_string_log_safe.replace(value, "x")
+        if secrets:
+            for value in secrets.values():
+                command_string_log_safe = command_string_log_safe.replace(value, "x")
 
+        log.info(command_string_log_safe)
         process = subprocess.Popen(command_string, stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=True)
 
         output, error = process.communicate()

odtp/workflow.py

@@ -1,13 +1,15 @@
 import os
 from odtp.run import DockerManager, OdtpRunSetupException
 import odtp.helpers.utils as odtp_utils
+import odtp.helpers.settings as config
 import odtp.helpers.environment as env_helpers
 import odtp.mongodb.db as db
 import logging
 import zipfile
 
 log = logging.getLogger(__name__)
-log.setLevel(logging.DEBUG)
+log.setLevel(logging.INFO)
+log.addHandler(config.get_command_log_handler())
 
 
 class WorkflowManager: