[system] Colored output (issues #65) (#141)

* feat: implement color wrapper

* feat: replace logging with colored printer

* fix: output to logging

* fix: stop output to stdout

* Revert "fix: stop output to stdout"

This reverts commit cf7209b.

* fix: revert intercepting on sebs.py

* feat: move color to utils.py

* feat: miliseconds

* feat: intercept @ logging base

* fix: rename vars to avoid conflict

* fix: remove legacy output

* fix: legacy imports

* fix: wrong return type

* fix: mypy precedence

* fix: mypy precedence

* fix: change precedence of colored printer

* fix: define return signature

* feat: colored wrapper

* fix: update to single handler

* fix: propagate only if file input exists

* feat: metadata before main message

sebs.py

@@ -122,6 +122,7 @@ def parse_common_params(
 
     sebs_client = sebs.SeBS(cache, output_dir, verbose, logging_filename)
     output_dir = sebs.utils.create_output(output_dir, preserve_out, verbose)
+
     sebs_client.logging.info("Created experiment output at {}".format(output_dir))
 
     # CLI overrides JSON options

sebs/utils.py

@@ -5,6 +5,9 @@
 import subprocess
 import sys
 import uuid
+import click
+import datetime
+
 from typing import List, Optional, TextIO, Union
 
 PROJECT_DIR = os.path.join(os.path.dirname(os.path.realpath(__file__)), os.pardir)
@@ -141,48 +144,101 @@ def global_logging():
     logging_date_format = "%H:%M:%S"
     logging.basicConfig(format=logging_format, datefmt=logging_date_format, level=logging.INFO)
 
+class ColoredWrapper:
+    SUCCESS = "\033[92m"
+    STATUS = "\033[94m"
+    WARNING = "\033[93m"
+    ERROR = "\033[91m"
+    BOLD = "\033[1m"
+    END = "\033[0m"
+
+    def __init__(self, prefix, logger, verbose=True, propagte=False):
+        self.verbose = verbose
+        self.propagte = propagte
+        self.prefix = prefix
+        self._logging = logger
+
+    def debug(self, message):
+        if self.verbose:
+            self._print(message, ColoredWrapper.STATUS)
+            if self.propagte:
+                self._logging.debug(message)
+
+    def info(self, message):
+        self._print(message, ColoredWrapper.SUCCESS)
+        if self.propagte:
+            self._logging.info(message)
+
+    def warning(self, message):
+        self._print(message, ColoredWrapper.WARNING)
+        if self.propagte:
+            self._logging.warning(message)
+
+    def error(self, message):
+        self._print(message, ColoredWrapper.ERROR)
+        if self.propagte:
+            self._logging.error(message)
+
+    def critical(self, message):
+        self._print(message, ColoredWrapper.ERROR)
+        if self.propagte:
+            self._logging.critical(message)
+
+    def _print(self, message, color):
+        timestamp = datetime.datetime.now().strftime("%H:%M:%S.%f")
+        click.echo(f"{color}{ColoredWrapper.BOLD}[{timestamp}]{ColoredWrapper.END} {self.prefix} {message}")
 
 class LoggingHandlers:
     def __init__(self, verbose: bool = False, filename: Optional[str] = None):
         logging_format = "%(asctime)s,%(msecs)d %(levelname)s %(name)s: %(message)s"
         logging_date_format = "%H:%M:%S"
         formatter = logging.Formatter(logging_format, logging_date_format)
-        self.handlers: List[Union[logging.FileHandler, logging.StreamHandler[TextIO]]] = []
+        self.handler: logging.FileHandler = None
 
-        # Add stdout output
-        if verbose:
-            stdout = logging.StreamHandler(sys.stdout)
-            stdout.setFormatter(formatter)
-            stdout.setLevel(logging.DEBUG if verbose else logging.INFO)
-            self.handlers.append(stdout)
+        # Remember verbosity for colored wrapper
+        self.verbosity = verbose
 
         # Add file output if needed
         if filename:
             file_out = logging.FileHandler(filename=filename, mode="w")
             file_out.setFormatter(formatter)
             file_out.setLevel(logging.DEBUG if verbose else logging.INFO)
-            self.handlers.append(file_out)
+            self.handler = file_out
 
 
 class LoggingBase:
     def __init__(self):
         uuid_name = str(uuid.uuid4())[0:4]
         if hasattr(self, "typename"):
-            self.logging = logging.getLogger(f"{self.typename()}-{uuid_name}")
+            self.log_name = f"{self.typename()}-{uuid_name}"
         else:
-            self.logging = logging.getLogger(f"{self.__class__.__name__}-{uuid_name}")
-        self.logging.setLevel(logging.INFO)
+            self.log_name = f"{self.__class__.__name__}-{uuid_name}"
 
+        self._logging = logging.getLogger(self.log_name)
+        self._logging.setLevel(logging.INFO)
+        self.wrapper = ColoredWrapper(self.log_name, self._logging)
+
+    @property
+    def logging(self) -> ColoredWrapper:
+        # This would always print log with color. And only if
+        # filename in LoggingHandlers is set, it would log to file.
+        return self.wrapper
+
     @property
     def logging_handlers(self) -> LoggingHandlers:
         return self._logging_handlers
 
     @logging_handlers.setter
     def logging_handlers(self, handlers: LoggingHandlers):
         self._logging_handlers = handlers
-        self.logging.propagate = False
-        for handler in handlers.handlers:
-            self.logging.addHandler(handler)
+
+        self._logging.propagate = False
+        self.wrapper = ColoredWrapper(self.log_name, self._logging, 
+                                      verbose=handlers.verbosity,
+                                      propagte=handlers.handler is not None)
+
+        if self._logging_handlers.handler is not None:
+            self._logging.addHandler(self._logging_handlers.handler)
 
 
 def has_platform(name: str) -> bool:
@@ -199,4 +255,4 @@ def handler(x, y):
         traceback.print_stack()
         sys.exit(signal.SIGINT)
 
-    signal.signal(signal.SIGINT, handler)
+    signal.signal(signal.SIGINT, handler)