Added logging to validation #17

src/specimen/hqtb/core/validation.py

@@ -11,6 +11,7 @@
 ################################################################################
 
 import cobra
+import logging
 import pprint
 import time
 
@@ -21,7 +22,7 @@
 # functions
 ################################################################################
 
-# @TODO: add more validation options.´
+# @TODO: add more validation options.
 
 def run(dir:str, model_path:str, tests:None|Literal['cobra']=None, run_all:bool=True):
     """SPECIMEN Step 4: Validate the model.
@@ -39,35 +40,59 @@ def run(dir:str, model_path:str, tests:None|Literal['cobra']=None, run_all:bool=
             the previous parameter.
             Defaults to True.
     """
+    # general logging
+    genlogger = logging.getLogger(__name__)
+
 
     total_time_s = time.time()
 
-    print('\nvalidation\n################################################################################\n')
-
     # -----------------------
     # create output directory
     # -----------------------
 
     try:
         Path(dir,"04_validation").mkdir(parents=True, exist_ok=False)
-        print(F'Creating new directory {str(Path(dir,"04_validation"))}')
+        genlogger.info(F'Creating new directory {str(Path(dir,"04_validation"))}', file='validation.log')
     except FileExistsError:
-        print('Given directory already has required structure.')
-
+        genlogger.info('Given directory already has required structure.')
+
+    # -------------
+    # setup logging
+    # -------------
+    Path(dir,"04_validation",'validation.log').unlink(missing_ok=True)
+    handler = logging.handlers.RotatingFileHandler(str(Path(dir,"04_validation",'validation.log')), mode='wa', maxBytes=1000, backupCount=10, encoding='utf-8', delay=0)
+    handler.setFormatter(logging.Formatter("{levelname} \t {name} \t {message}", 
+                                           style="{",))
+    # interal logging
+    logger = logging.getLogger(__name__+'-intern')
+    logger.setLevel(logging.DEBUG)
+    logger.propagate = False
+    logger.addHandler(handler)
+    # redirect cobrapy logging
+    cobralogger = logging.getLogger("cobra")
+    cobralogger.addHandler(handler)
+    cobralogger.propagate = False
+
     # --------------
     # validate model
     # --------------
+    logger.info('\nvalidation\n################################################################################\n')
 
     if run_all or (tests and 'cobra' in tests):
-        print('\n# ---------------------------------\n# validate model - cobra validation\n# ---------------------------------')
+        logger.info('\n# ---------------------------------\n# validate model - cobra validation\n# ---------------------------------')
         start = time.time()
 
         # validate using cobra
         cobra_report = cobra.io.validate_sbml_model(model_path)
-        pprint.pprint(cobra_report)
+        with open(Path(dir,"04_validation","cobrapy-validation.txt"),'w') as cpyval_file:
+            pprint.pprint(cobra_report, stream=cpyval_file) 
 
         end = time.time()
-        print(F'\ttime: {end - start}s')
+        logger.info(F'\ttime: {end - start}s')
 
     total_time_e = time.time()
-    print(F'total runtime: {total_time_e-total_time_s}')
+    logger.info(F'total runtime: {total_time_e-total_time_s}')
+
+    # restore cobrapy logging behaviour
+    cobralogger.handlers.clear()
+    cobralogger.propagate = False