Feature/colour (#44)

examples/bitgo/config.yaml

@@ -7,9 +7,14 @@ discovery:
   functions_folder_path: functions
   manifests_folder_path: manifests
 logging:
-  event_filters: []
+  event_filters:
+    - Specification
+    - Scenario
+    - Action
+    - Assertion
   log_file_path: log.jsonl
   logging_level: 5
+  log_format: "%(event)s - %(levelname)s - %(message)s"
 env_files:
   default: test
   packs:

examples/bitgo/test_e2e.py

@@ -17,3 +17,17 @@ def test_run(capsys: CaptureFixture):
     with capsys.disabled() as disabled:
         result = runner.invoke(app, ["run", "-m", "SpecificationModel"])
         assert result.exit_code == 0, "Result is non-zero"
+
+
+@pytest.mark.authenticated
+def test_run_spec_file(capsys: CaptureFixture):
+    with capsys.disabled() as disabled:
+        result = runner.invoke(
+            app,
+            [
+                "run",
+                "-f",
+                "./manifests/specifications/can_list_transfers_by_different_coins.yaml"
+            ]
+        )
+        assert result.exit_code == 0, "Result is non-zero"

src/api_compose/core/logging/__init__.py

@@ -10,8 +10,11 @@ def get_logger(
 ) -> LoggerAdapter:
     log_file_path = GlobalSettingsModelSingleton.get().logging.log_file_path
     logging_level = GlobalSettingsModelSingleton.get().logging.logging_level
+    log_format = GlobalSettingsModelSingleton.get().logging.log_format
     return LoggerAdapter(
         name=name,
         log_file_path=log_file_path,
         overwrite=overwrite,
-        logging_level=logging_level)
+        logging_level=logging_level,
+        log_format=log_format
+    )

src/api_compose/core/logging/adapter.py

@@ -8,7 +8,7 @@
 from lxml.etree import _Element
 from pydantic import BaseModel as _BaseModel
 
-from api_compose.core.events.base import BaseEvent
+from api_compose.core.events.base import BaseEvent, EventType
 from api_compose.core.events.default import DefaultEvent
 from api_compose.core.settings.settings import GlobalSettingsModelSingleton
 from api_compose.core.utils import _modify_json_encoder  # noqa - modify json.dump behaviour
@@ -21,12 +21,14 @@ def __init__(
             self,
             name,
             log_file_path: Path,
+            log_format: str,
             overwrite: bool = True,
-            logging_level=logging.DEBUG
+            logging_level=logging.DEBUG,
     ):
         self.name = name
         self.log_file_path = log_file_path
         self.logging_level = logging_level
+        self.log_format = log_format
 
         if overwrite:
             self._delete_log_file()
@@ -39,7 +41,7 @@ def _get_logger(self) -> logging.Logger:
         logger.setLevel(self.logging_level)
 
         stream_handler = logging.StreamHandler()
-        stream_handler.setFormatter(StreamFormatter())
+        stream_handler.setFormatter(StreamFormatter(self.log_format))
         stream_handler.addFilter(EventFilter())
         logger.addHandler(stream_handler)
 
@@ -121,6 +123,42 @@ def format(self, record: logging.LogRecord):
 
 
 class StreamFormatter(logging.Formatter):
+    BOLD_GREY = '\x1b[1;38;21m'
+    GREY = '\x1b[38;21m'
+    UNDERLINE_GREY = '\x1b[4;38;21m'
+
+    BLUE = '\x1b[38;5;39m'
+    BOLD_BLUE = '\x1b[1;38;5;39m'
+    UNDERLINE_BLUE = '\x1b[4;38;5;39m'
+    UNDERLINE_BOLD_BLUE = '\x1b[1;4;38;5;39m'
+
+    BOLD_YELLOW = '\x1b[4;38;5;226m'
+    YELLOW = '\x1b[38;5;226m'
+    UNDERLINE_YELLOW = '\x1b[1;38;5;226m'
+
+    BOLD_RED = '\x1b[1;38;5;196m'
+    RED = '\x1b[38;5;196m'
+    UNDERLINE_RED = '\x1b[4;38;5;196m'
+
+    RESET = '\x1b[0m'
+
+    def __init__(
+            self,
+            log_fmt: str,
+            *args,
+            **kwargs
+    ):
+        super().__init__(*args, **kwargs)
+        self.base_log_fmt = log_fmt
+        self.log_formats = {
+            EventType.Specification: self.UNDERLINE_BOLD_BLUE + self.base_log_fmt + self.RESET,
+            EventType.Scenario: self.BOLD_BLUE + self.base_log_fmt + self.RESET,
+            EventType.Action: self.BLUE + self.base_log_fmt + self.RESET,
+            EventType.Assertion: self.BLUE + self.base_log_fmt + self.RESET,
+        }
+
     def format(self, record: logging.LogRecord):
-        record.msg = f"[{getattr(record, 'event')}] : {record.levelname} - {record.msg}"
-        return super().format(record)
+        DEFAULT_LOG_FMT = self.GREY + self.base_log_fmt + self.RESET
+        log_fmt = self.log_formats.get(record.event, DEFAULT_LOG_FMT)
+        formatter = logging.Formatter(log_fmt)
+        return formatter.format(record)

src/api_compose/core/settings/settings.py

@@ -9,7 +9,7 @@
 import logging
 import uuid
 from pathlib import Path
-from typing import List, Optional, Dict, Set, Any, Literal, Annotated
+from typing import List, Optional, Dict, Any, Literal, Annotated
 
 from pydantic import Field, model_validator, computed_field, PlainSerializer, field_validator
 
@@ -56,15 +56,13 @@ class CliOptions(BaseSettings):
         description='Unique Identifier of session. For internal use only',
     )
 
-
     @field_validator('include_tags', 'exclude_tags', mode='before')
     @classmethod
     def validate_tags(cls, values):
         if type(values) == list:
             values = list(set(values))
         return values
 
-
     @field_validator('session_id', mode='before')
     @classmethod
     def validate_session_id(cls, values):
@@ -73,6 +71,7 @@ def validate_session_id(cls, values):
         else:
             return str(uuid.uuid4())
 
+
 class DiscoverySettings(BaseSettings):
     manifests_folder_path: JsonSerialisablePathAnnotation = Path('manifests')
     functions_folder_path: JsonSerialisablePathAnnotation = Path('functions')
@@ -115,7 +114,7 @@ class SelectorsPackSettings(BaseSettings):
         tags: List[str] = Field([], description='set of tags to look for in manifest(s)')
         models: List[str] = Field([], description='list of models to look for in manifest(s)')
 
-        @field_validator('tags',  mode='before')
+        @field_validator('tags', mode='before')
         @classmethod
         def validate_tags(cls, values):
             if type(values) == list:
@@ -157,7 +156,14 @@ def validate_pack(cls, m: 'SelectorsSettings'):
 class LoggingSettings(BaseSettings):
     logging_level: int = logging.DEBUG
     log_file_path: Optional[JsonSerialisablePathAnnotation] = Path('log.jsonl')
-    event_filters: List[EventType] = []
+    log_format: str = "%(event)s - %(levelname)s - %(message)s"
+    event_filters: List[EventType] = [
+        # Event Type which concerns the users
+        EventType.Specification,
+        EventType.Scenario,
+        EventType.Action,
+        EventType.Assertion
+    ]
 
 
 class ReportingSettings(BaseSettings):

src/api_compose/root/processors/scenario.py

@@ -6,6 +6,7 @@
 from api_compose.root.events import ScenarioEvent
 from api_compose.root.models.scenario import ScenarioModel
 from api_compose.root.processors.schedulers.scheduler import ActionScheduler
+from api_compose.services.assertion_service.events import AssertionEvent
 from api_compose.services.assertion_service.models.jinja_assertion import AssertionStateEnum
 from api_compose.services.assertion_service.processors.i_jinja_assertion import InteractiveJinjaAssertion
 from api_compose.services.assertion_service.processors.jinja_assertion import JinjaAssertion
@@ -56,31 +57,38 @@ def __init__(self,
         )
 
     def run(self):
-        logger.info(f'Running Scenario {self.scenario_model.fqn}', ScenarioEvent())
+        logger.info(f' Scenario started - {self.scenario_model.fqn}', ScenarioEvent())
         # Run Actions
         self.scenario_model.start_time = time.time()
         self.action_scheduler.run()
         self.scenario_model.end_time = time.time()
+        logger.info(f' Scenario ended - {self.scenario_model.fqn}', ScenarioEvent())
 
         # Get ActionJinjaContext
         jinja_context = ActionJinjaContext.build(
             backend=self.backend,
             action_model=self.scenario_model.actions[0],
             append_current_action_model=False,
         )
-        
+
         # Skip Assertions if not all actions are in ENDED state
+        logger.info(f'Assertions for scenario started - {self.scenario_model.fqn}', AssertionEvent())
         is_all_actions_ended = all(action.state == ActionStateEnum.ENDED for action in self.scenario_model.actions)
-        
+
         if is_all_actions_ended:
-            logger.info(f'Evaluating Assertions for scenario {self.scenario_model.fqn}', ScenarioEvent())
             if GlobalSettingsModelSingleton.get().cli_options.is_interactive:
                 # Dynamic Jinja Template Generation
                 if len(self.scenario_model.assertions) > 0:
-                    logger.warning(f'Pre-defined Assertions for Scenario {self.scenario_model.id} will be overwritten')
+                    logger.warning(
+                        f'Pre-defined Assertions for Scenario {self.scenario_model.id} will be overwritten',
+                        AssertionEvent()
+                    )
                     self.scenario_model.assertions = []
 
-                logger.info(f"Dropping to an interactive Jinja Session for Scenario {self.scenario_model.id=}")
+                logger.info(
+                    f"Dropping to an interactive Jinja Session for Scenario {self.scenario_model.id=}",
+                    AssertionEvent()
+                )
                 # Jinja Template is generated dynamically
                 i_jinja_assertion = InteractiveJinjaAssertion(
                     jinja_engine=self.jinja_engine,
@@ -98,9 +106,16 @@ def run(self):
                     )
                     jinja_assertion.run()
         else:
-            logger.error(f'Discarding Assertions for scenario {self.scenario_model.fqn} as not all actions are in {ActionStateEnum.ENDED}', ScenarioEvent())
+            logger.error(
+                f'Discarding Assertions for scenario {self.scenario_model.fqn} as not all actions are in {ActionStateEnum.ENDED}',
+                AssertionEvent()
+            )
             for assertion_model in self.scenario_model.assertions:
                 assertion_model.state = AssertionStateEnum.DISCARDED
-
+        logger.info(
+            f'Assertions for scenario ended - {self.scenario_model.fqn} as not all actions are in {ActionStateEnum.ENDED}',
+            AssertionEvent()
+        )
+
         # Save results
         self.backend.add(self.scenario_model)

src/api_compose/root/processors/specification.py

@@ -35,7 +35,7 @@ def __init__(self,
         self.backend = backend
 
     def run(self):
-        logger.info(f'Running Specification {self.specification_model.fqn}', SpecificationEvent())
+        logger.info(f'Specification Started - {self.specification_model.fqn}', SpecificationEvent())
         for idx, scenario_model in enumerate(self.specification_model.scenarios):
             scenario_controller = ScenarioProcessor(
                 scenario_model=scenario_model,
@@ -45,4 +45,5 @@ def run(self):
 
             scenario_controller.run()
 
+        logger.info(f'Specification Ended - {self.specification_model.fqn}', SpecificationEvent())
         self.backend.add(self.specification_model)