Logger is now an attribute of the execution context

src/core/sheerka/ExecutionContext.py

@@ -3,8 +3,8 @@ import time
 
 from core.builtin_concepts import BuiltinConcepts
 from core.concept import Concept
+from core.sheerka_logger import get_logger
 from sdp.sheerkaDataProvider import Event
-from sheerkapickle.SheerkaPickler import SheerkaPickler
 
 DEBUG_TAB_SIZE = 4
 
@@ -21,6 +21,8 @@ PROPERTIES_TO_SERIALIZE = ("_id",
                            "concepts")
 
 
+
+
 class ExecutionContext:
     """
     To keep track of the execution of a request
@@ -41,6 +43,7 @@ class ExecutionContext:
                  event: Event,
                  sheerka,
                  desc: str = None,
+                 logger=None,
                  **kwargs):
 
         self._parent = None
@@ -56,6 +59,7 @@ class ExecutionContext:
         self.desc = desc  # human description of what is going on
         self.children = []
         self.preprocess = None
+        self.logger = logger
 
         self.inputs = {}  # what was the parameters of the execution context
         self.values = {}  # what was produced by the execution context
@@ -66,6 +70,9 @@ class ExecutionContext:
         for k, v in kwargs.items():
             self._bag[k] = v
 
+        self.stat_log = get_logger("stats")
+        self.show_stats = False
+
     @property
     def elapsed(self):
         if self._start == 0:
@@ -91,10 +98,13 @@ class ExecutionContext:
 
     def __enter__(self):
         self._start = time.time_ns()
+        self.log_new()
         return self
 
     def __exit__(self, exc_type, exc_val, exc_tb):
         self._stop = time.time_ns()
+        if self.show_stats:
+            self.stat_log.debug(f"[{self._id:2}]" + self._tab + "Execution time: " + self.elapsed_str)
 
     def __repr__(self):
         msg = f"ExecutionContext(who={self.who}, id={self._id}"
@@ -103,6 +113,11 @@ class ExecutionContext:
         msg += ")"
         return msg
 
+    def __str__(self):
+        msg = self.desc or "New Context"
+        msg += f", who={self.who}, id={self.id}"
+        return msg
+
     def __eq__(self, other):
         if id(self) == id(other):
             return True
@@ -183,8 +198,9 @@ class ExecutionContext:
 
         return self.sheerka.new(key, **kwargs)
 
-    def push(self, who=None, desc=None, **kwargs):
+    def push(self, who=None, desc=None, logger=None, **kwargs):
         who = who or self.who
+        logger = logger or self.logger
         _kwargs = {"obj": self.obj, "concepts": self.concepts}
         _kwargs.update(self._bag)
         _kwargs.update(kwargs)
@@ -193,6 +209,7 @@ class ExecutionContext:
             self.event,
             self.sheerka,
             desc,
+            logger,
             **_kwargs,
         )
         new._parent = self
@@ -202,25 +219,29 @@ class ExecutionContext:
         self.children.append(new)
         return new
 
-    def log_new(self, logger):
-        logger.debug(f"[{self._id:2}]" + self._tab + str(self))
+    def log_new(self):
+        if self.logger and not self.logger.disabled:
+            self.logger.debug(f"[{self._id:2}]" + self._tab + str(self))
+            self.show_stats = True
 
-    def log(self, logger, message, who=None):
-        logger.debug(f"[{self._id:2}]" + self._tab + (f"[{who}] " if who else "") + str(message))
+    def log(self, message, who=None):
+        if self.logger and not self.logger.disabled:
+            self.logger.debug(f"[{self._id:2}]" + self._tab + (f"[{who}] " if who else "") + str(message))
 
-    def log_error(self, logger, message, who=None):
-        logger.exception(f"[{self._id:2}]" + self._tab + (f"[{who}] " if who else "") + str(message))
+    def log_error(self, message, who=None):
+        if self.logger and not self.logger.disabled:
+            self.logger.exception(f"[{self._id:2}]" + self._tab + (f"[{who}] " if who else "") + str(message))
 
-    def log_result(self, logger, return_values):
-        if not logger.isEnabledFor(logging.DEBUG):
+    def log_result(self, return_values):
+        if not self.logger or not self.logger.isEnabledFor(logging.DEBUG):
             return
 
         if len(return_values) == 0:
-            logger.debug(self._tab + "No return value")
+            self.logger.debug(self._tab + "No return value")
 
         for r in return_values:
             to_str = self.return_value_to_str(r)
-            logger.debug(f"[{self._id:2}]" + self._tab + "-> " + to_str)
+            self.logger.debug(f"[{self._id:2}]" + self._tab + "-> " + to_str)
 
     def get_parent(self):
         return self._parent