From f121465661969e76970539461cfc5b755446e469 Mon Sep 17 00:00:00 2001 From: Vladimir Filonov Date: Sat, 12 Oct 2024 19:14:52 +0400 Subject: [PATCH 1/8] User can set exact provider log level using environment variable `KEEP_PROVIDER_{}_LOG_LEVEL` --- keep/contextmanager/contextmanager.py | 23 +++++++++++++++++++---- keep/providers/base/base_provider.py | 1 + tests/test_contextmanager.py | 15 +++++++++++++++ 3 files changed, 35 insertions(+), 4 deletions(-) diff --git a/keep/contextmanager/contextmanager.py b/keep/contextmanager/contextmanager.py index c46502f58..eeca97560 100644 --- a/keep/contextmanager/contextmanager.py +++ b/keep/contextmanager/contextmanager.py @@ -10,12 +10,13 @@ class ContextManager: def __init__(self, tenant_id, workflow_id=None, workflow_execution_id=None): - self.logger = logging.getLogger(__name__) - self.logger_adapter = WorkflowLoggerAdapter( - self.logger, self, tenant_id, workflow_id, workflow_execution_id - ) + self.workflow_id = workflow_id + self.workflow_execution_id = workflow_execution_id self.tenant_id = tenant_id + self.logger = None + self.logger_adapter = None + self.set_logger(logging.getLogger(__name__)) self.steps_context = {} self.steps_context_size = 0 self.providers_context = {} @@ -74,6 +75,20 @@ def set_execution_context(self, workflow_execution_id): self.workflow_execution_id = workflow_execution_id self.logger_adapter.workflow_execution_id = workflow_execution_id + def set_logger_by_name(self, logger_name): + logger = logging.getLogger(logger_name) + log_level_string = os.environ.get("KEEP_PROVIDER_{}_LOG_LEVEL".format(logger_name.upper()), None) + if log_level_string: + log_level = logging.getLevelName(log_level_string) + logger.setLevel(log_level) + self.set_logger(logger) + + def set_logger(self, logger): + self.logger = logger + self.logger_adapter = WorkflowLoggerAdapter( + self.logger, self, self.tenant_id, self.workflow_id, self.workflow_execution_id + ) + def get_logger(self): return self.logger_adapter diff --git a/keep/providers/base/base_provider.py b/keep/providers/base/base_provider.py index 758c848de..d9e21fc7e 100644 --- a/keep/providers/base/base_provider.py +++ b/keep/providers/base/base_provider.py @@ -66,6 +66,7 @@ def __init__( self.webhook_markdown = webhook_markdown self.provider_description = provider_description self.context_manager = context_manager + context_manager.set_logger_by_name("provider_{}".format(self.provider_id)) self.logger = context_manager.get_logger() self.validate_config() self.logger.debug( diff --git a/tests/test_contextmanager.py b/tests/test_contextmanager.py index fad627e5d..c5dbf57fc 100644 --- a/tests/test_contextmanager.py +++ b/tests/test_contextmanager.py @@ -3,6 +3,8 @@ """ import json +import logging +import os import tempfile import pytest @@ -209,3 +211,16 @@ def test_context_manager_get_last_alert_run( def test_context_manager_singleton(context_manager: ContextManager): with pytest.raises(Exception): ContextManager() + + +def test_custom_logger_with_env_based_level(context_manager: ContextManager): + + # Default log levelD + assert context_manager.get_logger().getEffectiveLevel() == logging.WARNING + + context_manager.set_logger_by_name("test") + assert context_manager.get_logger().getEffectiveLevel() == logging.WARNING + + os.environ["KEEP_PROVIDER_TEST_LOG_LEVEL"] = "DEBUG" + context_manager.set_logger_by_name("test") + assert context_manager.get_logger().getEffectiveLevel() == logging.DEBUG From 4d24cb31ab3c335123a2067eb1cb1c0adbfb6f06 Mon Sep 17 00:00:00 2001 From: Vladimir Filonov Date: Sat, 12 Oct 2024 19:55:15 +0400 Subject: [PATCH 2/8] Fix default effectiveLevel in test_custom_logger_with_env_based_level test --- tests/test_contextmanager.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tests/test_contextmanager.py b/tests/test_contextmanager.py index c5dbf57fc..0c9c6b2e4 100644 --- a/tests/test_contextmanager.py +++ b/tests/test_contextmanager.py @@ -216,10 +216,10 @@ def test_context_manager_singleton(context_manager: ContextManager): def test_custom_logger_with_env_based_level(context_manager: ContextManager): # Default log levelD - assert context_manager.get_logger().getEffectiveLevel() == logging.WARNING + assert context_manager.get_logger().getEffectiveLevel() == logging.INFO context_manager.set_logger_by_name("test") - assert context_manager.get_logger().getEffectiveLevel() == logging.WARNING + assert context_manager.get_logger().getEffectiveLevel() == logging.INFO os.environ["KEEP_PROVIDER_TEST_LOG_LEVEL"] = "DEBUG" context_manager.set_logger_by_name("test") From 7ff8f117b8454cceb7d18f719417713ee0b4cd2e Mon Sep 17 00:00:00 2001 From: Vladimir Filonov Date: Mon, 14 Oct 2024 16:54:36 +0400 Subject: [PATCH 3/8] Add super-simple test to check workflow execution logs --- tests/test_workflow_execution.py | 67 +++++++++++++++++++++++++++++++- 1 file changed, 66 insertions(+), 1 deletion(-) diff --git a/tests/test_workflow_execution.py b/tests/test_workflow_execution.py index 2faabce1b..17910e42a 100644 --- a/tests/test_workflow_execution.py +++ b/tests/test_workflow_execution.py @@ -8,7 +8,7 @@ from keep.api.core.db import get_last_workflow_execution_by_workflow_id from keep.api.core.dependencies import SINGLE_TENANT_UUID from keep.api.models.alert import AlertDto, AlertStatus, IncidentDto -from keep.api.models.db.workflow import Workflow +from keep.api.models.db.workflow import Workflow, WorkflowExecutionLog from keep.workflowmanager.workflowmanager import WorkflowManager from tests.fixtures.client import client, test_app # noqa @@ -794,3 +794,68 @@ def wait_workflow_execution(workflow_id): assert workflow_execution_deleted.results["mock-action"] == [ '"deleted incident: incident"\n' ] + + +@pytest.mark.parametrize( + "test_app, test_case, alert_statuses, expected_tier, db_session", + [ + ({"AUTH_TYPE": "NOAUTH"}, "No action", [[0, "firing"]], None, None), + ], + indirect=["test_app", "db_session"], +) +def test_workflow_execution_logs( + db_session, + test_app, + create_alert, + setup_workflow, + workflow_manager, + test_case, + alert_statuses, + expected_tier, +): + base_time = datetime.now(tz=pytz.utc) + + # Create alerts with specified statuses and timestamps + alert_statuses.reverse() + for time_diff, status in alert_statuses: + alert_status = ( + AlertStatus.FIRING if status == "firing" else AlertStatus.RESOLVED + ) + create_alert("fp1", alert_status, base_time - timedelta(minutes=time_diff)) + + time.sleep(1) + # Create the current alert + current_alert = AlertDto( + id="grafana-1", + source=["grafana"], + name="server-is-down", + status=AlertStatus.FIRING, + severity="critical", + fingerprint="fp1", + ) + + # Insert the current alert into the workflow manager + workflow_manager.insert_events(SINGLE_TENANT_UUID, [current_alert]) + + # Wait for the workflow execution to complete + workflow_execution = None + count = 0 + status = None + while workflow_execution is None and count < 30 and status != "success": + workflow_execution = get_last_workflow_execution_by_workflow_id( + SINGLE_TENANT_UUID, "alert-time-check" + ) + if workflow_execution is not None: + status = workflow_execution.status + time.sleep(1) + count += 1 + + # Check if the workflow execution was successful + assert workflow_execution is not None + assert workflow_execution.status == "success" + + logs = db_session.query(WorkflowExecutionLog).filter( + WorkflowExecutionLog.workflow_execution_id == workflow_execution.id + ).all() + + assert len(logs) == 4 \ No newline at end of file From 633d3d57782aa13da26f981327e35341bb0e2df1 Mon Sep 17 00:00:00 2001 From: Tal Borenstein Date: Mon, 14 Oct 2024 19:22:50 +0300 Subject: [PATCH 4/8] feat: test --- keep/contextmanager/contextmanager.py | 41 +++++++++--------- keep/providers/base/base_provider.py | 3 +- tests/test_workflow_execution.py | 62 ++++++++++++++++++++++++--- 3 files changed, 77 insertions(+), 29 deletions(-) diff --git a/keep/contextmanager/contextmanager.py b/keep/contextmanager/contextmanager.py index eeca97560..ce55e2cda 100644 --- a/keep/contextmanager/contextmanager.py +++ b/keep/contextmanager/contextmanager.py @@ -10,13 +10,13 @@ class ContextManager: def __init__(self, tenant_id, workflow_id=None, workflow_execution_id=None): - + self.logger = logging.getLogger(__name__) + self.logger_adapter = WorkflowLoggerAdapter( + self.logger, self, tenant_id, workflow_id, workflow_execution_id + ) self.workflow_id = workflow_id self.workflow_execution_id = workflow_execution_id self.tenant_id = tenant_id - self.logger = None - self.logger_adapter = None - self.set_logger(logging.getLogger(__name__)) self.steps_context = {} self.steps_context_size = 0 self.providers_context = {} @@ -54,6 +54,7 @@ def __init__(self, tenant_id, workflow_id=None, workflow_execution_id=None): self.dependencies = set() self.workflow_execution_id = None self._api_key = None + self.__loggers = [] @property def api_key(self): @@ -74,23 +75,23 @@ def api_key(self): def set_execution_context(self, workflow_execution_id): self.workflow_execution_id = workflow_execution_id self.logger_adapter.workflow_execution_id = workflow_execution_id - - def set_logger_by_name(self, logger_name): - logger = logging.getLogger(logger_name) - log_level_string = os.environ.get("KEEP_PROVIDER_{}_LOG_LEVEL".format(logger_name.upper()), None) - if log_level_string: - log_level = logging.getLevelName(log_level_string) - logger.setLevel(log_level) - self.set_logger(logger) - - def set_logger(self, logger): - self.logger = logger - self.logger_adapter = WorkflowLoggerAdapter( - self.logger, self, self.tenant_id, self.workflow_id, self.workflow_execution_id + for logger in self.__loggers: + logger.workflow_execution_id = workflow_execution_id + + def get_logger(self, name=None): + if not name: + return self.logger_adapter + + logger = logging.getLogger(name) + logger_adapter = WorkflowLoggerAdapter( + logger, + self, + self.tenant_id, + self.workflow_id, + self.workflow_execution_id, ) - - def get_logger(self): - return self.logger_adapter + self.__loggers.append(logger_adapter) + return logger_adapter def set_event_context(self, event): self.event_context = event diff --git a/keep/providers/base/base_provider.py b/keep/providers/base/base_provider.py index d9e21fc7e..844524551 100644 --- a/keep/providers/base/base_provider.py +++ b/keep/providers/base/base_provider.py @@ -66,8 +66,7 @@ def __init__( self.webhook_markdown = webhook_markdown self.provider_description = provider_description self.context_manager = context_manager - context_manager.set_logger_by_name("provider_{}".format(self.provider_id)) - self.logger = context_manager.get_logger() + self.logger = context_manager.get_logger(self.__class__.__name__) self.validate_config() self.logger.debug( "Base provider initalized", extra={"provider": self.__class__.__name__} diff --git a/tests/test_workflow_execution.py b/tests/test_workflow_execution.py index 17910e42a..b55ad118b 100644 --- a/tests/test_workflow_execution.py +++ b/tests/test_workflow_execution.py @@ -44,6 +44,33 @@ """ +workflow_definition_with_two_providers = """workflow: +id: susu-and-sons +description: Just to test the logs of 2 providers +triggers: +- type: alert + filters: + - key: name + value: "server-is-hamburger" +steps: +- name: keep_step + provider: + type: keep + with: + filters: + - key: status + value: open +actions: +- name: console_action + provider: + type: console + with: + message: | + "Tier 1 Alert: {{ alert.name }} - {{ alert.description }} + Alert details: {{ alert }}" +""" + + @pytest.fixture(scope="module") def workflow_manager(): """ @@ -77,6 +104,25 @@ def setup_workflow(db_session): db_session.commit() +@pytest.fixture +def setup_workflow_with_two_providers(db_session): + """ + Fixture to set up a workflow in the database before each test. + It creates a Workflow object with the predefined workflow definition and adds it to the database. + """ + workflow = Workflow( + id="susu-and-sons", + name="susu-and-sons", + tenant_id=SINGLE_TENANT_UUID, + description="some stuff for unit testing", + created_by="tal@keephq.dev", + interval=0, + workflow_raw=workflow_definition_with_two_providers, + ) + db_session.add(workflow) + db_session.commit() + + @pytest.mark.parametrize( "test_app, test_case, alert_statuses, expected_tier, db_session", [ @@ -807,7 +853,7 @@ def test_workflow_execution_logs( db_session, test_app, create_alert, - setup_workflow, + setup_workflow_with_two_providers, workflow_manager, test_case, alert_statuses, @@ -828,7 +874,7 @@ def test_workflow_execution_logs( current_alert = AlertDto( id="grafana-1", source=["grafana"], - name="server-is-down", + name="server-is-hamburger", status=AlertStatus.FIRING, severity="critical", fingerprint="fp1", @@ -843,7 +889,7 @@ def test_workflow_execution_logs( status = None while workflow_execution is None and count < 30 and status != "success": workflow_execution = get_last_workflow_execution_by_workflow_id( - SINGLE_TENANT_UUID, "alert-time-check" + SINGLE_TENANT_UUID, "susu-and-sons" ) if workflow_execution is not None: status = workflow_execution.status @@ -854,8 +900,10 @@ def test_workflow_execution_logs( assert workflow_execution is not None assert workflow_execution.status == "success" - logs = db_session.query(WorkflowExecutionLog).filter( - WorkflowExecutionLog.workflow_execution_id == workflow_execution.id - ).all() + logs = ( + db_session.query(WorkflowExecutionLog) + .filter(WorkflowExecutionLog.workflow_execution_id == workflow_execution.id) + .all() + ) - assert len(logs) == 4 \ No newline at end of file + assert len(logs) == 15 From b2cf2ebdba07bc1cd66f089623780a8f3d5e7b79 Mon Sep 17 00:00:00 2001 From: Tal Borenstein Date: Mon, 14 Oct 2024 19:25:34 +0300 Subject: [PATCH 5/8] fix: remove reundant test --- tests/test_contextmanager.py | 15 --------------- 1 file changed, 15 deletions(-) diff --git a/tests/test_contextmanager.py b/tests/test_contextmanager.py index 0c9c6b2e4..fad627e5d 100644 --- a/tests/test_contextmanager.py +++ b/tests/test_contextmanager.py @@ -3,8 +3,6 @@ """ import json -import logging -import os import tempfile import pytest @@ -211,16 +209,3 @@ def test_context_manager_get_last_alert_run( def test_context_manager_singleton(context_manager: ContextManager): with pytest.raises(Exception): ContextManager() - - -def test_custom_logger_with_env_based_level(context_manager: ContextManager): - - # Default log levelD - assert context_manager.get_logger().getEffectiveLevel() == logging.INFO - - context_manager.set_logger_by_name("test") - assert context_manager.get_logger().getEffectiveLevel() == logging.INFO - - os.environ["KEEP_PROVIDER_TEST_LOG_LEVEL"] = "DEBUG" - context_manager.set_logger_by_name("test") - assert context_manager.get_logger().getEffectiveLevel() == logging.DEBUG From 241776163a3801ec850e023b12c6de0508511b67 Mon Sep 17 00:00:00 2001 From: Tal Borenstein Date: Tue, 15 Oct 2024 09:42:28 +0300 Subject: [PATCH 6/8] chore: test --- keep/providers/base/base_provider.py | 1 + tests/test_workflow_execution.py | 69 ++++++++++++++++++++++++++++ 2 files changed, 70 insertions(+) diff --git a/keep/providers/base/base_provider.py b/keep/providers/base/base_provider.py index 844524551..e8bbd06a8 100644 --- a/keep/providers/base/base_provider.py +++ b/keep/providers/base/base_provider.py @@ -67,6 +67,7 @@ def __init__( self.provider_description = provider_description self.context_manager = context_manager self.logger = context_manager.get_logger(self.__class__.__name__) + self.logger.setLevel(os.environ.get("KEEP_CONSOLE_PROVIDER_LOG_LEVEL", "INFO")) self.validate_config() self.logger.debug( "Base provider initalized", extra={"provider": self.__class__.__name__} diff --git a/tests/test_workflow_execution.py b/tests/test_workflow_execution.py index b55ad118b..74e4d372e 100644 --- a/tests/test_workflow_execution.py +++ b/tests/test_workflow_execution.py @@ -907,3 +907,72 @@ def test_workflow_execution_logs( ) assert len(logs) == 15 + + +@pytest.mark.parametrize( + "test_app, test_case, alert_statuses, expected_tier, db_session", + [ + ({"AUTH_TYPE": "NOAUTH"}, "No action", [[0, "firing"]], None, None), + ], + indirect=["test_app", "db_session"], +) +def test_workflow_execution_logs_log_level_debug_console_provider( + db_session, + test_app, + create_alert, + setup_workflow_with_two_providers, + workflow_manager, + test_case, + alert_statuses, + expected_tier, + monkeypatch, +): + base_time = datetime.now(tz=pytz.utc) + monkeypatch.setenv("KEEP_CONSOLE_PROVIDER_LOG_LEVEL", "DEBUG") + + # Create alerts with specified statuses and timestamps + alert_statuses.reverse() + for time_diff, status in alert_statuses: + alert_status = ( + AlertStatus.FIRING if status == "firing" else AlertStatus.RESOLVED + ) + create_alert("fp1", alert_status, base_time - timedelta(minutes=time_diff)) + + time.sleep(1) + # Create the current alert + current_alert = AlertDto( + id="grafana-1", + source=["grafana"], + name="server-is-hamburger", + status=AlertStatus.FIRING, + severity="critical", + fingerprint="fp1", + ) + + # Insert the current alert into the workflow manager + workflow_manager.insert_events(SINGLE_TENANT_UUID, [current_alert]) + + # Wait for the workflow execution to complete + workflow_execution = None + count = 0 + status = None + while workflow_execution is None and count < 30 and status != "success": + workflow_execution = get_last_workflow_execution_by_workflow_id( + SINGLE_TENANT_UUID, "susu-and-sons" + ) + if workflow_execution is not None: + status = workflow_execution.status + time.sleep(1) + count += 1 + + # Check if the workflow execution was successful + assert workflow_execution is not None + assert workflow_execution.status == "success" + + logs = ( + db_session.query(WorkflowExecutionLog) + .filter(WorkflowExecutionLog.workflow_execution_id == workflow_execution.id) + .all() + ) + + assert len(logs) == 17 # 15 + 2 debug logs from console provider From 3596efdf68ff22ba29ccd72af7af383825fb3093 Mon Sep 17 00:00:00 2001 From: Vladimir Filonov Date: Tue, 15 Oct 2024 16:58:11 +0400 Subject: [PATCH 7/8] Make test less hardcoded --- keep/providers/base/base_provider.py | 9 +- tests/test_workflow_execution.py | 218 ++++++++++++++++----------- 2 files changed, 141 insertions(+), 86 deletions(-) diff --git a/keep/providers/base/base_provider.py b/keep/providers/base/base_provider.py index e8bbd06a8..ed0275e31 100644 --- a/keep/providers/base/base_provider.py +++ b/keep/providers/base/base_provider.py @@ -66,8 +66,13 @@ def __init__( self.webhook_markdown = webhook_markdown self.provider_description = provider_description self.context_manager = context_manager - self.logger = context_manager.get_logger(self.__class__.__name__) - self.logger.setLevel(os.environ.get("KEEP_CONSOLE_PROVIDER_LOG_LEVEL", "INFO")) + self.logger = context_manager.get_logger(self.provider_id) + self.logger.setLevel( + os.environ.get( + "KEEP_{}_PROVIDER_LOG_LEVEL".format(self.provider_id.upper()), + "INFO" + ) + ) self.validate_config() self.logger.debug( "Base provider initalized", extra={"provider": self.__class__.__name__} diff --git a/tests/test_workflow_execution.py b/tests/test_workflow_execution.py index 74e4d372e..8fb29a8f8 100644 --- a/tests/test_workflow_execution.py +++ b/tests/test_workflow_execution.py @@ -1,12 +1,17 @@ import asyncio +import logging import time +from collections import defaultdict from datetime import datetime, timedelta +from functools import partial +from unittest.mock import patch import pytest import pytz from keep.api.core.db import get_last_workflow_execution_by_workflow_id from keep.api.core.dependencies import SINGLE_TENANT_UUID +from keep.api.logging import WorkflowLoggerAdapter from keep.api.models.alert import AlertDto, AlertStatus, IncidentDto from keep.api.models.db.workflow import Workflow, WorkflowExecutionLog from keep.workflowmanager.workflowmanager import WorkflowManager @@ -842,6 +847,35 @@ def wait_workflow_execution(workflow_id): ] + +logs_counter = {} + +def count_logs(instance, original_method): + log_levels = logging.getLevelNamesMapping() + def wrapper(*args, **kwargs): + level_name = original_method.__name__.upper() + max_level = instance.getEffectiveLevel() + current_level = log_levels[level_name] + if current_level >= max_level: + logs_counter.setdefault(instance.workflow_execution_id, defaultdict(int)) + logs_counter[instance.workflow_execution_id]["all"] += 1 + logs_counter[instance.workflow_execution_id][level_name] += 1 + + return original_method(*args, **kwargs) + + return wrapper + +def fake_workflow_adapter(logger, context_manager, tenant_id, workflow_id, workflow_execution_id): + adapter = WorkflowLoggerAdapter(logger, context_manager, tenant_id, workflow_id, workflow_execution_id) + + adapter.info = count_logs(adapter, adapter.info) + adapter.debug = count_logs(adapter, adapter.debug) + adapter.warning = count_logs(adapter, adapter.warning) + adapter.error = count_logs(adapter, adapter.error) + adapter.critical = count_logs(adapter, adapter.critical) + return adapter + + @pytest.mark.parametrize( "test_app, test_case, alert_statuses, expected_tier, db_session", [ @@ -859,54 +893,57 @@ def test_workflow_execution_logs( alert_statuses, expected_tier, ): - base_time = datetime.now(tz=pytz.utc) + with patch('keep.contextmanager.contextmanager.WorkflowLoggerAdapter', + side_effect=fake_workflow_adapter),\ + patch('keep.api.logging.RUNNING_IN_CLOUD_RUN', value=True): + base_time = datetime.now(tz=pytz.utc) + + # Create alerts with specified statuses and timestamps + alert_statuses.reverse() + for time_diff, status in alert_statuses: + alert_status = ( + AlertStatus.FIRING if status == "firing" else AlertStatus.RESOLVED + ) + create_alert("fp1", alert_status, base_time - timedelta(minutes=time_diff)) - # Create alerts with specified statuses and timestamps - alert_statuses.reverse() - for time_diff, status in alert_statuses: - alert_status = ( - AlertStatus.FIRING if status == "firing" else AlertStatus.RESOLVED + time.sleep(1) + # Create the current alert + current_alert = AlertDto( + id="grafana-1", + source=["grafana"], + name="server-is-hamburger", + status=AlertStatus.FIRING, + severity="critical", + fingerprint="fp1", ) - create_alert("fp1", alert_status, base_time - timedelta(minutes=time_diff)) - time.sleep(1) - # Create the current alert - current_alert = AlertDto( - id="grafana-1", - source=["grafana"], - name="server-is-hamburger", - status=AlertStatus.FIRING, - severity="critical", - fingerprint="fp1", - ) - - # Insert the current alert into the workflow manager - workflow_manager.insert_events(SINGLE_TENANT_UUID, [current_alert]) + # Insert the current alert into the workflow manager + workflow_manager.insert_events(SINGLE_TENANT_UUID, [current_alert]) - # Wait for the workflow execution to complete - workflow_execution = None - count = 0 - status = None - while workflow_execution is None and count < 30 and status != "success": - workflow_execution = get_last_workflow_execution_by_workflow_id( - SINGLE_TENANT_UUID, "susu-and-sons" - ) - if workflow_execution is not None: - status = workflow_execution.status - time.sleep(1) - count += 1 + # Wait for the workflow execution to complete + workflow_execution = None + count = 0 + status = None + while workflow_execution is None and count < 30 and status != "success": + workflow_execution = get_last_workflow_execution_by_workflow_id( + SINGLE_TENANT_UUID, "susu-and-sons" + ) + if workflow_execution is not None: + status = workflow_execution.status + time.sleep(1) + count += 1 - # Check if the workflow execution was successful - assert workflow_execution is not None - assert workflow_execution.status == "success" + # Check if the workflow execution was successful + assert workflow_execution is not None + assert workflow_execution.status == "success" - logs = ( - db_session.query(WorkflowExecutionLog) - .filter(WorkflowExecutionLog.workflow_execution_id == workflow_execution.id) - .all() - ) + logs = ( + db_session.query(WorkflowExecutionLog) + .filter(WorkflowExecutionLog.workflow_execution_id == workflow_execution.id) + .all() + ) - assert len(logs) == 15 + assert len(logs) == logs_counter[workflow_execution.id]["all"] @pytest.mark.parametrize( @@ -927,52 +964,65 @@ def test_workflow_execution_logs_log_level_debug_console_provider( expected_tier, monkeypatch, ): - base_time = datetime.now(tz=pytz.utc) - monkeypatch.setenv("KEEP_CONSOLE_PROVIDER_LOG_LEVEL", "DEBUG") - # Create alerts with specified statuses and timestamps - alert_statuses.reverse() - for time_diff, status in alert_statuses: - alert_status = ( - AlertStatus.FIRING if status == "firing" else AlertStatus.RESOLVED - ) - create_alert("fp1", alert_status, base_time - timedelta(minutes=time_diff)) + logs_counts = {} + logs_level_counts = {} + for level in ["INFO", "DEBUG"]: + monkeypatch.setenv("KEEP_CONSOLE_PROVIDER_LOG_LEVEL", level) + with patch('keep.contextmanager.contextmanager.WorkflowLoggerAdapter', + side_effect=fake_workflow_adapter), \ + patch('keep.api.logging.RUNNING_IN_CLOUD_RUN', value=True): + base_time = datetime.now(tz=pytz.utc) + + # Create alerts with specified statuses and timestamps + alert_statuses.reverse() + for time_diff, status in alert_statuses: + alert_status = ( + AlertStatus.FIRING if status == "firing" else AlertStatus.RESOLVED + ) + create_alert("fp1", alert_status, base_time - timedelta(minutes=time_diff)) - time.sleep(1) - # Create the current alert - current_alert = AlertDto( - id="grafana-1", - source=["grafana"], - name="server-is-hamburger", - status=AlertStatus.FIRING, - severity="critical", - fingerprint="fp1", - ) + time.sleep(1) + # Create the current alert + current_alert = AlertDto( + id="grafana-1-{}".format(level), + source=["grafana"], + name="server-is-hamburger", + status=AlertStatus.FIRING, + severity="critical", + fingerprint="fp1-{}".format(level), + ) - # Insert the current alert into the workflow manager - workflow_manager.insert_events(SINGLE_TENANT_UUID, [current_alert]) + # Insert the current alert into the workflow manager + workflow_manager.insert_events(SINGLE_TENANT_UUID, [current_alert]) - # Wait for the workflow execution to complete - workflow_execution = None - count = 0 - status = None - while workflow_execution is None and count < 30 and status != "success": - workflow_execution = get_last_workflow_execution_by_workflow_id( - SINGLE_TENANT_UUID, "susu-and-sons" + # Wait for the workflow execution to complete + workflow_execution = None + count = 0 + status = None + time.sleep(1) + while workflow_execution is None and count < 30 and status != "success": + workflow_execution = get_last_workflow_execution_by_workflow_id( + SINGLE_TENANT_UUID, "susu-and-sons" + ) + if workflow_execution is not None: + status = workflow_execution.status + time.sleep(1) + count += 1 + + # Check if the workflow execution was successful + assert workflow_execution is not None + assert workflow_execution.status == "success" + + logs_counts[workflow_execution.id] = logs_counter[workflow_execution.id]["all"] + logs_level_counts[level] = logs_counter[workflow_execution.id]["all"] + + for workflow_execution_id in logs_counts: + logs = ( + db_session.query(WorkflowExecutionLog) + .filter(WorkflowExecutionLog.workflow_execution_id == workflow_execution_id) + .all() ) - if workflow_execution is not None: - status = workflow_execution.status - time.sleep(1) - count += 1 - - # Check if the workflow execution was successful - assert workflow_execution is not None - assert workflow_execution.status == "success" - - logs = ( - db_session.query(WorkflowExecutionLog) - .filter(WorkflowExecutionLog.workflow_execution_id == workflow_execution.id) - .all() - ) + assert logs_counts[workflow_execution_id] == len(logs) - assert len(logs) == 17 # 15 + 2 debug logs from console provider + assert logs_level_counts["DEBUG"] > logs_level_counts["INFO"] From b2ef2718e7599be8aaf5c14f088fa8d3df0f0270 Mon Sep 17 00:00:00 2001 From: Tal Borenstein Date: Tue, 15 Oct 2024 18:15:37 +0300 Subject: [PATCH 8/8] fix: comment pr --- keep/contextmanager/contextmanager.py | 9 ++++++--- keep/providers/base/base_provider.py | 2 +- 2 files changed, 7 insertions(+), 4 deletions(-) diff --git a/keep/contextmanager/contextmanager.py b/keep/contextmanager/contextmanager.py index ce55e2cda..b044962c4 100644 --- a/keep/contextmanager/contextmanager.py +++ b/keep/contextmanager/contextmanager.py @@ -54,7 +54,7 @@ def __init__(self, tenant_id, workflow_id=None, workflow_execution_id=None): self.dependencies = set() self.workflow_execution_id = None self._api_key = None - self.__loggers = [] + self.__loggers = {} @property def api_key(self): @@ -75,13 +75,16 @@ def api_key(self): def set_execution_context(self, workflow_execution_id): self.workflow_execution_id = workflow_execution_id self.logger_adapter.workflow_execution_id = workflow_execution_id - for logger in self.__loggers: + for logger in self.__loggers.values(): logger.workflow_execution_id = workflow_execution_id def get_logger(self, name=None): if not name: return self.logger_adapter + if name in self.__loggers: + return self.__loggers[name] + logger = logging.getLogger(name) logger_adapter = WorkflowLoggerAdapter( logger, @@ -90,7 +93,7 @@ def get_logger(self, name=None): self.workflow_id, self.workflow_execution_id, ) - self.__loggers.append(logger_adapter) + self.__loggers[name] = logger_adapter return logger_adapter def set_event_context(self, event): diff --git a/keep/providers/base/base_provider.py b/keep/providers/base/base_provider.py index ed0275e31..0233b5837 100644 --- a/keep/providers/base/base_provider.py +++ b/keep/providers/base/base_provider.py @@ -70,7 +70,7 @@ def __init__( self.logger.setLevel( os.environ.get( "KEEP_{}_PROVIDER_LOG_LEVEL".format(self.provider_id.upper()), - "INFO" + os.environ.get("LOG_LEVEL", "INFO"), ) ) self.validate_config()