diff --git a/examples/bitgo/config.yaml b/examples/bitgo/config.yaml index 515685b..7eb2f03 100644 --- a/examples/bitgo/config.yaml +++ b/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: diff --git a/examples/bitgo/test_e2e.py b/examples/bitgo/test_e2e.py index a824bb9..7256023 100644 --- a/examples/bitgo/test_e2e.py +++ b/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" diff --git a/src/api_compose/core/logging/__init__.py b/src/api_compose/core/logging/__init__.py index 71c5b69..0f86a21 100644 --- a/src/api_compose/core/logging/__init__.py +++ b/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 + ) diff --git a/src/api_compose/core/logging/adapter.py b/src/api_compose/core/logging/adapter.py index b9d862f..29487ce 100644 --- a/src/api_compose/core/logging/adapter.py +++ b/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) diff --git a/src/api_compose/core/settings/settings.py b/src/api_compose/core/settings/settings.py index 93a85fb..7467dca 100644 --- a/src/api_compose/core/settings/settings.py +++ b/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,7 +56,6 @@ 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): @@ -64,7 +63,6 @@ def validate_tags(cls, values): 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): diff --git a/src/api_compose/root/processors/scenario.py b/src/api_compose/root/processors/scenario.py index 6844d98..2e069a5 100644 --- a/src/api_compose/root/processors/scenario.py +++ b/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,11 +57,12 @@ 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( @@ -68,19 +70,25 @@ def run(self): 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) diff --git a/src/api_compose/root/processors/specification.py b/src/api_compose/root/processors/specification.py index 276dae1..2a69127 100644 --- a/src/api_compose/root/processors/specification.py +++ b/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)