Merge pull request #181 from fair-workflows/fix-retrospective-logging

Fix retrospective logging

Author: svenvanderburg

fairworkflows/config.py

@@ -1,3 +1,4 @@
+import logging
 from pathlib import Path
 
 PACKAGE_DIR = Path(__file__).parent.absolute()
@@ -11,3 +12,5 @@
 
 DUMMY_FAIRWORKFLOWS_URI = 'http://fairworkflows.org'
 IS_FAIRSTEP_RETURN_VALUE_PARAMETER_NAME='returns'
+
+LOGGER = logging.getLogger('fairworkflows')

fairworkflows/fairstep.py

@@ -1,3 +1,4 @@
+import functools
 import sys
 import inspect
 import typing
@@ -10,9 +11,11 @@
 from rdflib import RDF, RDFS, DCTERMS
 
 from fairworkflows import namespaces, LinguisticSystem, LINGSYS_ENGLISH, LINGSYS_PYTHON
-from fairworkflows.config import DUMMY_FAIRWORKFLOWS_URI, IS_FAIRSTEP_RETURN_VALUE_PARAMETER_NAME
+from fairworkflows.config import DUMMY_FAIRWORKFLOWS_URI, IS_FAIRSTEP_RETURN_VALUE_PARAMETER_NAME, \
+    LOGGER
 from fairworkflows.rdf_wrapper import RdfWrapper, replace_in_rdf
 
+
 class FairVariable:
     """Represents a variable.
 
@@ -425,16 +428,24 @@ def _modify_function(func):
         inputs = _extract_inputs_from_function(func, kwargs)
         outputs = _extract_outputs_from_function(func, kwargs)
 
-        func._fairstep = FairStep(uri='http://www.example.org/unpublished-'+func.__name__,
-                                  label=label,
-                                  description=description,
-                                  is_pplan_step=is_pplan_step,
-                                  is_manual_task=is_manual_task,
-                                  is_script_task=is_script_task,
-                                  language=LINGSYS_PYTHON,
-                                  inputs=inputs,
-                                  outputs=outputs)
-
+        fairstep = FairStep(uri='http://www.example.org/unpublished-'+func.__name__,
+                            label=label,
+                            description=description,
+                            is_pplan_step=is_pplan_step,
+                            is_manual_task=is_manual_task,
+                            is_script_task=is_script_task,
+                            language=LINGSYS_PYTHON,
+                            inputs=inputs,
+                            outputs=outputs)
+
+        @functools.wraps
+        def _add_logging(func):
+            def _wrapper(*func_args, **func_kwargs):
+                LOGGER.info(f'Running step: {func.__name__}')
+                return func(*func_args, **func_kwargs)
+            return _wrapper
+        func = _add_logging(func)
+        func._fairstep = fairstep
         return noodles.schedule(func)
 
     return _modify_function

fairworkflows/fairworkflow.py

@@ -16,6 +16,7 @@
 from rdflib.tools.rdf2dot import rdf2dot
 from requests import HTTPError
 
+from fairworkflows.config import LOGGER
 from fairworkflows import namespaces, LinguisticSystem, LINGSYS_ENGLISH, LINGSYS_PYTHON
 from fairworkflows.fairstep import FairStep
 from fairworkflows.rdf_wrapper import RdfWrapper
@@ -376,9 +377,8 @@ def execute(self, *args, **kwargs):
         formatter = logging.Formatter('%(asctime)s - %(message)s')
         log_handler.setFormatter(formatter)
 
-        logger = logging.getLogger('noodles')
-        logger.setLevel(logging.INFO)
-        logger.handlers = [log_handler]
+        LOGGER.setLevel(logging.INFO)
+        LOGGER.handlers = [log_handler]
         self.workflow_level_promise = noodles.workflow.from_call(
             noodles.get_workflow(self.workflow_level_promise).root_node.foo, args, kwargs, {})
         result = noodles.run_single(self.workflow_level_promise)

tests/test_fairworkflow.py

@@ -4,6 +4,7 @@
 
 import pytest
 import rdflib
+from nanopub.definitions import DUMMY_NANOPUB_URI
 from requests import HTTPError
 
 from conftest import skip_if_nanopub_server_unavailable, read_rdf_test_resource
@@ -351,8 +352,13 @@ def my_workflow(in1, in2, in3):
 
         result, prov = fw.execute(1, 4, 3)
         assert result == -66
+
         assert isinstance(prov, Publication)
 
+        prov_log = str(list(prov.assertion.objects(rdflib.URIRef(f'{DUMMY_NANOPUB_URI}#retroprov'),
+                                                   rdflib.RDFS.label))[0])
+        assert 'Running step: add' in prov_log
+
     def test_workflow_complex_serialization(self):
         class OtherType:
             def __init__(self, message):