From 8be56c8673959605f59e4865b286da7c2aaf0c3a Mon Sep 17 00:00:00 2001 From: Colin Date: Mon, 11 Sep 2023 16:09:42 -0700 Subject: [PATCH 01/14] add set_package_log_level functionality --- core/dbt/events/adapter_endpoint.py | 6 +++++- core/dbt/events/functions.py | 10 ++++++++-- 2 files changed, 13 insertions(+), 3 deletions(-) diff --git a/core/dbt/events/adapter_endpoint.py b/core/dbt/events/adapter_endpoint.py index 7e5cf0cd1d3..6feb219103d 100644 --- a/core/dbt/events/adapter_endpoint.py +++ b/core/dbt/events/adapter_endpoint.py @@ -1,6 +1,6 @@ import traceback from dataclasses import dataclass -from dbt.events.functions import fire_event +from dbt.events.functions import fire_event, set_package_log_level from dbt.events.contextvars import get_node_info from dbt.events.types import ( AdapterEventDebug, @@ -56,3 +56,7 @@ def critical(self, msg, *args): name=self.name, base_msg=str(msg), args=list(args), node_info=get_node_info() ) fire_event(event) + + @staticmethod + def set_adapter_dependency_log_level(package_name, level): + set_package_log_level(package_name, level) diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py index c0d895ab80c..f39875d8066 100644 --- a/core/dbt/events/functions.py +++ b/core/dbt/events/functions.py @@ -1,3 +1,5 @@ +import logging + from dbt.constants import METADATA_ENV_PREFIX from dbt.events.base_types import BaseEvent, EventLevel, EventMsg from dbt.events.eventmgr import EventManager, LoggerConfig, LineFormat, NoFilter, IEventManager @@ -9,7 +11,7 @@ import json import os import sys -from typing import Callable, Dict, List, Optional, TextIO +from typing import Callable, Dict, List, Optional, TextIO, Union import uuid from google.protobuf.json_format import MessageToDict @@ -94,7 +96,6 @@ def _get_stdout_config( level: EventLevel, log_cache_events: bool, ) -> LoggerConfig: - return LoggerConfig( name="stdout_log", level=level, @@ -296,3 +297,8 @@ def set_invocation_id() -> None: def ctx_set_event_manager(event_manager: IEventManager): global EVENT_MANAGER EVENT_MANAGER = event_manager + + +def set_package_log_level(package_name: str, level: Union[str, int]): + log = logging.getLogger(package_name) + log.setLevel(level) From 2b2f1696d1000985efc333a957d739d902b81150 Mon Sep 17 00:00:00 2001 From: Colin Date: Mon, 11 Sep 2023 16:52:18 -0700 Subject: [PATCH 02/14] set package handler --- core/dbt/events/adapter_endpoint.py | 4 ++-- core/dbt/events/functions.py | 5 +++-- 2 files changed, 5 insertions(+), 4 deletions(-) diff --git a/core/dbt/events/adapter_endpoint.py b/core/dbt/events/adapter_endpoint.py index 6feb219103d..ac1df235204 100644 --- a/core/dbt/events/adapter_endpoint.py +++ b/core/dbt/events/adapter_endpoint.py @@ -1,6 +1,6 @@ import traceback from dataclasses import dataclass -from dbt.events.functions import fire_event, set_package_log_level +from dbt.events.functions import fire_event, set_package_logging from dbt.events.contextvars import get_node_info from dbt.events.types import ( AdapterEventDebug, @@ -59,4 +59,4 @@ def critical(self, msg, *args): @staticmethod def set_adapter_dependency_log_level(package_name, level): - set_package_log_level(package_name, level) + set_package_logging(package_name, level) diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py index f39875d8066..6d7eaf32786 100644 --- a/core/dbt/events/functions.py +++ b/core/dbt/events/functions.py @@ -299,6 +299,7 @@ def ctx_set_event_manager(event_manager: IEventManager): EVENT_MANAGER = event_manager -def set_package_log_level(package_name: str, level: Union[str, int]): +def set_package_logging(package_name: str, default_level: Union[str, int]): log = logging.getLogger(package_name) - log.setLevel(level) + log.setLevel(default_level) + log.addHandler(logging.StreamHandler(sys.stdout)) From 427b9b34cb1ea18e2821cbc2c0c0cefe8d8af762 Mon Sep 17 00:00:00 2001 From: Colin Date: Mon, 11 Sep 2023 17:01:20 -0700 Subject: [PATCH 03/14] set package handler --- core/dbt/events/functions.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py index 6d7eaf32786..78488368fc3 100644 --- a/core/dbt/events/functions.py +++ b/core/dbt/events/functions.py @@ -302,4 +302,6 @@ def ctx_set_event_manager(event_manager: IEventManager): def set_package_logging(package_name: str, default_level: Union[str, int]): log = logging.getLogger(package_name) log.setLevel(default_level) - log.addHandler(logging.StreamHandler(sys.stdout)) + std_out_handler = logging.StreamHandler(sys.stdout) + std_out_handler.setLevel(default_level) + log.addHandler(std_out_handler) From 81dccdee8d8e1d2de8e0781185c25b095cbe1666 Mon Sep 17 00:00:00 2001 From: Colin Date: Tue, 12 Sep 2023 13:25:41 -0700 Subject: [PATCH 04/14] add logging about stting up logging --- core/dbt/events/eventmgr.py | 8 ++------ core/dbt/events/functions.py | 18 ++++++++++++++++-- 2 files changed, 18 insertions(+), 8 deletions(-) diff --git a/core/dbt/events/eventmgr.py b/core/dbt/events/eventmgr.py index b715879563f..6837e3402df 100644 --- a/core/dbt/events/eventmgr.py +++ b/core/dbt/events/eventmgr.py @@ -14,6 +14,7 @@ from dbt.events.base_types import BaseEvent, EventLevel, msg_from_base_event, EventMsg import dbt.utils +from dbt.events.functions import get_rotating_file_handler # A Filter is a function which takes a BaseEvent and returns True if the event # should be logged, False otherwise. @@ -98,12 +99,7 @@ def __init__(self, event_manager: "EventManager", config: LoggerConfig) -> None: self._python_logger = self._get_python_log_for_handler(stream_handler) if config.output_file_name: - file_handler = RotatingFileHandler( - filename=str(config.output_file_name), - encoding="utf8", - maxBytes=config.output_file_max_bytes, # type: ignore - backupCount=5, - ) + file_handler = get_rotating_file_handler(config.output_file_name, config.output_file_max_bytes) self._python_logger = self._get_python_log_for_handler(file_handler) def _get_python_log_for_handler(self, handler: logging.Handler): diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py index 78488368fc3..aceb1a8dab6 100644 --- a/core/dbt/events/functions.py +++ b/core/dbt/events/functions.py @@ -1,4 +1,5 @@ import logging +from logging.handlers import RotatingFileHandler from dbt.constants import METADATA_ENV_PREFIX from dbt.events.base_types import BaseEvent, EventLevel, EventMsg @@ -18,6 +19,7 @@ import dbt.utils LOG_VERSION = 3 +OUTPUT_STREAM = sys.stdout metadata_vars: Optional[Dict[str, str]] = None # These are the logging events issued by the "clean" command, @@ -107,7 +109,7 @@ def _get_stdout_config( log_cache_events, line_format, ), - output_stream=sys.stdout, + output_stream=OUTPUT_STREAM, ) @@ -299,9 +301,21 @@ def ctx_set_event_manager(event_manager: IEventManager): EVENT_MANAGER = event_manager +def get_rotating_file_handler(output_file_name, output_file_max_bytes) -> RotatingFileHandler: + return RotatingFileHandler( + filename=str(output_file_name), + encoding="utf8", + maxBytes=output_file_max_bytes, # type: ignore + backupCount=5, + ) + def set_package_logging(package_name: str, default_level: Union[str, int]): log = logging.getLogger(package_name) log.setLevel(default_level) - std_out_handler = logging.StreamHandler(sys.stdout) + flags = get_flags() + log_file = os.path.join(flags.LOG_PATH, "dbt.log") + file_handler = get_rotating_file_handler(log_file, flags.LOG_SIZE_BYTES) + log.addHandler(file_handler) + std_out_handler = logging.StreamHandler(_CAPTURE_STREAM if _CAPTURE_STREAM else OUTPUT_STREAM) std_out_handler.setLevel(default_level) log.addHandler(std_out_handler) From a5d8f4eeb5c1d3c1484f6726d8ba552aec2aec6e Mon Sep 17 00:00:00 2001 From: Colin Date: Thu, 14 Sep 2023 17:16:18 -0700 Subject: [PATCH 05/14] test event log handler --- core/dbt/events/eventmgr.py | 5 +++-- core/dbt/events/functions.py | 21 +++++++++------------ core/dbt/events/handler.py | 15 +++++++++++++++ 3 files changed, 27 insertions(+), 14 deletions(-) create mode 100644 core/dbt/events/handler.py diff --git a/core/dbt/events/eventmgr.py b/core/dbt/events/eventmgr.py index 6837e3402df..159b27c6c52 100644 --- a/core/dbt/events/eventmgr.py +++ b/core/dbt/events/eventmgr.py @@ -5,7 +5,6 @@ from enum import Enum import json import logging -from logging.handlers import RotatingFileHandler import threading import traceback from typing import Any, Callable, List, Optional, TextIO, Protocol @@ -99,7 +98,9 @@ def __init__(self, event_manager: "EventManager", config: LoggerConfig) -> None: self._python_logger = self._get_python_log_for_handler(stream_handler) if config.output_file_name: - file_handler = get_rotating_file_handler(config.output_file_name, config.output_file_max_bytes) + file_handler = get_rotating_file_handler( + config.output_file_name, config.output_file_max_bytes + ) self._python_logger = self._get_python_log_for_handler(file_handler) def _get_python_log_for_handler(self, handler: logging.Handler): diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py index aceb1a8dab6..90bbbad22cf 100644 --- a/core/dbt/events/functions.py +++ b/core/dbt/events/functions.py @@ -4,6 +4,7 @@ from dbt.constants import METADATA_ENV_PREFIX from dbt.events.base_types import BaseEvent, EventLevel, EventMsg from dbt.events.eventmgr import EventManager, LoggerConfig, LineFormat, NoFilter, IEventManager +from dbt.events.handler import DbtLoggingHandler from dbt.events.helpers import env_secrets, scrub_secrets from dbt.events.types import Note from dbt.flags import get_flags, ENABLE_LEGACY_LOGGER @@ -303,19 +304,15 @@ def ctx_set_event_manager(event_manager: IEventManager): def get_rotating_file_handler(output_file_name, output_file_max_bytes) -> RotatingFileHandler: return RotatingFileHandler( - filename=str(output_file_name), - encoding="utf8", - maxBytes=output_file_max_bytes, # type: ignore - backupCount=5, - ) + filename=str(output_file_name), + encoding="utf8", + maxBytes=output_file_max_bytes, # type: ignore + backupCount=5, + ) + def set_package_logging(package_name: str, default_level: Union[str, int]): log = logging.getLogger(package_name) log.setLevel(default_level) - flags = get_flags() - log_file = os.path.join(flags.LOG_PATH, "dbt.log") - file_handler = get_rotating_file_handler(log_file, flags.LOG_SIZE_BYTES) - log.addHandler(file_handler) - std_out_handler = logging.StreamHandler(_CAPTURE_STREAM if _CAPTURE_STREAM else OUTPUT_STREAM) - std_out_handler.setLevel(default_level) - log.addHandler(std_out_handler) + event_handler = DbtLoggingHandler(event_manager=EVENT_MANAGER) + log.addHandler(event_handler) diff --git a/core/dbt/events/handler.py b/core/dbt/events/handler.py new file mode 100644 index 00000000000..6d35ca63b71 --- /dev/null +++ b/core/dbt/events/handler.py @@ -0,0 +1,15 @@ +import logging + +from dbt.events.types import Note + +from dbt.events.eventmgr import IEventManager + + +class DbtLoggingHandler(logging.Handler): + def __init__(self, event_manager: IEventManager, level=logging.NOTSET): + super().__init__(level) + self.event_manager = event_manager + + def emit(self, record: logging.LogRecord): + note = Note(message=record.getMessage()) + self.event_manager.fire_event(e=note) From 28c501b00535f2999eaa7047f8e1791ca7520750 Mon Sep 17 00:00:00 2001 From: Colin Date: Thu, 14 Sep 2023 17:39:13 -0700 Subject: [PATCH 06/14] add event log handler --- core/dbt/events/adapter_endpoint.py | 5 +++-- core/dbt/events/eventmgr.py | 10 +++++++--- core/dbt/events/functions.py | 22 +--------------------- core/dbt/events/handler.py | 10 ++++++++++ 4 files changed, 21 insertions(+), 26 deletions(-) diff --git a/core/dbt/events/adapter_endpoint.py b/core/dbt/events/adapter_endpoint.py index ac1df235204..75bcafbcf53 100644 --- a/core/dbt/events/adapter_endpoint.py +++ b/core/dbt/events/adapter_endpoint.py @@ -1,7 +1,8 @@ import traceback from dataclasses import dataclass -from dbt.events.functions import fire_event, set_package_logging +from dbt.events.functions import fire_event, EVENT_MANAGER from dbt.events.contextvars import get_node_info +from dbt.events.handler import set_package_logging from dbt.events.types import ( AdapterEventDebug, AdapterEventInfo, @@ -59,4 +60,4 @@ def critical(self, msg, *args): @staticmethod def set_adapter_dependency_log_level(package_name, level): - set_package_logging(package_name, level) + set_package_logging(package_name, level, EVENT_MANAGER) diff --git a/core/dbt/events/eventmgr.py b/core/dbt/events/eventmgr.py index 159b27c6c52..bbd36b69d35 100644 --- a/core/dbt/events/eventmgr.py +++ b/core/dbt/events/eventmgr.py @@ -1,4 +1,6 @@ import os +from logging.handlers import RotatingFileHandler + from colorama import Style from dataclasses import dataclass from datetime import datetime @@ -13,7 +15,6 @@ from dbt.events.base_types import BaseEvent, EventLevel, msg_from_base_event, EventMsg import dbt.utils -from dbt.events.functions import get_rotating_file_handler # A Filter is a function which takes a BaseEvent and returns True if the event # should be logged, False otherwise. @@ -98,8 +99,11 @@ def __init__(self, event_manager: "EventManager", config: LoggerConfig) -> None: self._python_logger = self._get_python_log_for_handler(stream_handler) if config.output_file_name: - file_handler = get_rotating_file_handler( - config.output_file_name, config.output_file_max_bytes + file_handler = RotatingFileHandler( + filename=str(config.output_file_name), + encoding="utf8", + maxBytes=config.output_file_max_bytes, # type: ignore + backupCount=5, ) self._python_logger = self._get_python_log_for_handler(file_handler) diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py index 90bbbad22cf..0e909ed5694 100644 --- a/core/dbt/events/functions.py +++ b/core/dbt/events/functions.py @@ -1,10 +1,6 @@ -import logging -from logging.handlers import RotatingFileHandler - from dbt.constants import METADATA_ENV_PREFIX from dbt.events.base_types import BaseEvent, EventLevel, EventMsg from dbt.events.eventmgr import EventManager, LoggerConfig, LineFormat, NoFilter, IEventManager -from dbt.events.handler import DbtLoggingHandler from dbt.events.helpers import env_secrets, scrub_secrets from dbt.events.types import Note from dbt.flags import get_flags, ENABLE_LEGACY_LOGGER @@ -13,7 +9,7 @@ import json import os import sys -from typing import Callable, Dict, List, Optional, TextIO, Union +from typing import Callable, Dict, List, Optional, TextIO import uuid from google.protobuf.json_format import MessageToDict @@ -300,19 +296,3 @@ def set_invocation_id() -> None: def ctx_set_event_manager(event_manager: IEventManager): global EVENT_MANAGER EVENT_MANAGER = event_manager - - -def get_rotating_file_handler(output_file_name, output_file_max_bytes) -> RotatingFileHandler: - return RotatingFileHandler( - filename=str(output_file_name), - encoding="utf8", - maxBytes=output_file_max_bytes, # type: ignore - backupCount=5, - ) - - -def set_package_logging(package_name: str, default_level: Union[str, int]): - log = logging.getLogger(package_name) - log.setLevel(default_level) - event_handler = DbtLoggingHandler(event_manager=EVENT_MANAGER) - log.addHandler(event_handler) diff --git a/core/dbt/events/handler.py b/core/dbt/events/handler.py index 6d35ca63b71..80f01beeca1 100644 --- a/core/dbt/events/handler.py +++ b/core/dbt/events/handler.py @@ -1,4 +1,5 @@ import logging +from typing import Union from dbt.events.types import Note @@ -13,3 +14,12 @@ def __init__(self, event_manager: IEventManager, level=logging.NOTSET): def emit(self, record: logging.LogRecord): note = Note(message=record.getMessage()) self.event_manager.fire_event(e=note) + + +def set_package_logging( + package_name: str, default_level: Union[str, int], event_mgr: IEventManager +): + log = logging.getLogger(package_name) + log.setLevel(default_level) + event_handler = DbtLoggingHandler(event_manager=event_mgr) + log.addHandler(event_handler) From b9609040a4d6e7577ebdd5dde47aaaf68da7d3d9 Mon Sep 17 00:00:00 2001 From: Colin Date: Thu, 14 Sep 2023 18:03:29 -0700 Subject: [PATCH 07/14] add event log level --- core/dbt/events/handler.py | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/core/dbt/events/handler.py b/core/dbt/events/handler.py index 80f01beeca1..1e5068599f7 100644 --- a/core/dbt/events/handler.py +++ b/core/dbt/events/handler.py @@ -1,6 +1,7 @@ import logging from typing import Union +from dbt.events.base_types import EventLevel from dbt.events.types import Note from dbt.events.eventmgr import IEventManager @@ -12,8 +13,9 @@ def __init__(self, event_manager: IEventManager, level=logging.NOTSET): self.event_manager = event_manager def emit(self, record: logging.LogRecord): - note = Note(message=record.getMessage()) - self.event_manager.fire_event(e=note) + note = Note(msg=record.getMessage()) + level = EventLevel(record.levelname) + self.event_manager.fire_event(e=note, level=level) def set_package_logging( From a70a0d67df695d2ab2eb70a978869da23d82cf04 Mon Sep 17 00:00:00 2001 From: Colin Date: Thu, 14 Sep 2023 21:29:22 -0700 Subject: [PATCH 08/14] rename package and add unit tests --- core/dbt/events/adapter_endpoint.py | 2 +- .../events/{handler.py => event_handler.py} | 21 ++++++++++++--- tests/unit/test_event_handler.py | 27 +++++++++++++++++++ 3 files changed, 46 insertions(+), 4 deletions(-) rename core/dbt/events/{handler.py => event_handler.py} (52%) create mode 100644 tests/unit/test_event_handler.py diff --git a/core/dbt/events/adapter_endpoint.py b/core/dbt/events/adapter_endpoint.py index 75bcafbcf53..eda87ba31d0 100644 --- a/core/dbt/events/adapter_endpoint.py +++ b/core/dbt/events/adapter_endpoint.py @@ -2,7 +2,7 @@ from dataclasses import dataclass from dbt.events.functions import fire_event, EVENT_MANAGER from dbt.events.contextvars import get_node_info -from dbt.events.handler import set_package_logging +from dbt.events.event_handler import set_package_logging from dbt.events.types import ( AdapterEventDebug, AdapterEventInfo, diff --git a/core/dbt/events/handler.py b/core/dbt/events/event_handler.py similarity index 52% rename from core/dbt/events/handler.py rename to core/dbt/events/event_handler.py index 1e5068599f7..14d6b5110e4 100644 --- a/core/dbt/events/handler.py +++ b/core/dbt/events/event_handler.py @@ -7,14 +7,29 @@ from dbt.events.eventmgr import IEventManager -class DbtLoggingHandler(logging.Handler): +def log_level_to_event_level(log_level: int) -> EventLevel: + if log_level == logging.DEBUG: + return EventLevel.DEBUG + elif log_level == logging.INFO: + return EventLevel.INFO + elif log_level == logging.WARNING: + return EventLevel.WARN + elif log_level == logging.ERROR: + return EventLevel.ERROR + elif log_level == logging.CRITICAL: + return EventLevel.ERROR + else: + return EventLevel.DEBUG + + +class DbtEventLoggingHandler(logging.Handler): def __init__(self, event_manager: IEventManager, level=logging.NOTSET): super().__init__(level) self.event_manager = event_manager def emit(self, record: logging.LogRecord): note = Note(msg=record.getMessage()) - level = EventLevel(record.levelname) + level = log_level_to_event_level(record.levelno) self.event_manager.fire_event(e=note, level=level) @@ -23,5 +38,5 @@ def set_package_logging( ): log = logging.getLogger(package_name) log.setLevel(default_level) - event_handler = DbtLoggingHandler(event_manager=event_mgr) + event_handler = DbtEventLoggingHandler(event_manager=event_mgr) log.addHandler(event_handler) diff --git a/tests/unit/test_event_handler.py b/tests/unit/test_event_handler.py new file mode 100644 index 00000000000..482add83046 --- /dev/null +++ b/tests/unit/test_event_handler.py @@ -0,0 +1,27 @@ +import logging + +from dbt.events.base_types import EventLevel +from dbt.events.event_handler import DbtEventLoggingHandler +from dbt.events.eventmgr import TestEventManager + + +def test_event_logging_handler_emits_records_correctly(): + event_manager = TestEventManager() + handler = DbtEventLoggingHandler(event_manager=event_manager) + log = logging.getLogger("test") + log.setLevel(logging.DEBUG) + log.addHandler(handler) + + log.debug("test") + log.info("test") + log.warning("test") + log.error("test") + log.exception("test") + log.critical("test") + assert len(event_manager.event_history) == 6 + assert event_manager.event_history[0][1] == EventLevel.DEBUG + assert event_manager.event_history[1][1] == EventLevel.INFO + assert event_manager.event_history[2][1] == EventLevel.WARN + assert event_manager.event_history[3][1] == EventLevel.ERROR + assert event_manager.event_history[4][1] == EventLevel.ERROR + assert event_manager.event_history[5][1] == EventLevel.ERROR From e8f0c420743f0ead869a9a4b2675029d44d322d0 Mon Sep 17 00:00:00 2001 From: Colin Date: Thu, 14 Sep 2023 21:30:53 -0700 Subject: [PATCH 09/14] revert logfile config change --- core/dbt/events/functions.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py index 0e909ed5694..c38416ef2de 100644 --- a/core/dbt/events/functions.py +++ b/core/dbt/events/functions.py @@ -16,7 +16,6 @@ import dbt.utils LOG_VERSION = 3 -OUTPUT_STREAM = sys.stdout metadata_vars: Optional[Dict[str, str]] = None # These are the logging events issued by the "clean" command, @@ -106,7 +105,7 @@ def _get_stdout_config( log_cache_events, line_format, ), - output_stream=OUTPUT_STREAM, + output_stream=sys.stdout, ) @@ -125,6 +124,7 @@ def _get_logfile_config( level: EventLevel, log_file_max_bytes: int, ) -> LoggerConfig: + return LoggerConfig( name="file_log", line_format=line_format, From f5092b14a0947d0b1993674c914959dc8b62d30c Mon Sep 17 00:00:00 2001 From: Colin Date: Fri, 15 Sep 2023 12:35:44 -0700 Subject: [PATCH 10/14] cleanup and add code comments --- core/dbt/events/adapter_endpoint.py | 3 +++ core/dbt/events/event_handler.py | 14 +++++++++----- 2 files changed, 12 insertions(+), 5 deletions(-) diff --git a/core/dbt/events/adapter_endpoint.py b/core/dbt/events/adapter_endpoint.py index eda87ba31d0..56a83a41e4d 100644 --- a/core/dbt/events/adapter_endpoint.py +++ b/core/dbt/events/adapter_endpoint.py @@ -60,4 +60,7 @@ def critical(self, msg, *args): @staticmethod def set_adapter_dependency_log_level(package_name, level): + """By default dbt suppresses non-dbt package logs. This method allows + you to set the log level for a specific package. + """ set_package_logging(package_name, level, EVENT_MANAGER) diff --git a/core/dbt/events/event_handler.py b/core/dbt/events/event_handler.py index 14d6b5110e4..6c79bf652f9 100644 --- a/core/dbt/events/event_handler.py +++ b/core/dbt/events/event_handler.py @@ -23,6 +23,11 @@ def log_level_to_event_level(log_level: int) -> EventLevel: class DbtEventLoggingHandler(logging.Handler): + """A logging handler that wraps the EventManager + This allows non-dbt packages to log to the dbt event stream. + All logs are generated as "Note" events. + """ + def __init__(self, event_manager: IEventManager, level=logging.NOTSET): super().__init__(level) self.event_manager = event_manager @@ -33,10 +38,9 @@ def emit(self, record: logging.LogRecord): self.event_manager.fire_event(e=note, level=level) -def set_package_logging( - package_name: str, default_level: Union[str, int], event_mgr: IEventManager -): +def set_package_logging(package_name: str, log_level: Union[str, int], event_mgr: IEventManager): + """Attach dbt's custom logging handler to the package's logger.""" log = logging.getLogger(package_name) - log.setLevel(default_level) - event_handler = DbtEventLoggingHandler(event_manager=event_mgr) + log.setLevel(log_level) + event_handler = DbtEventLoggingHandler(event_manager=event_mgr, level=log_level) log.addHandler(event_handler) From b1f880fd4cc374a816ad74a9c255e653f62677a2 Mon Sep 17 00:00:00 2001 From: Colin Date: Fri, 15 Sep 2023 12:37:44 -0700 Subject: [PATCH 11/14] add changie --- .changes/unreleased/Features-20230915-123733.yaml | 6 ++++++ 1 file changed, 6 insertions(+) create mode 100644 .changes/unreleased/Features-20230915-123733.yaml diff --git a/.changes/unreleased/Features-20230915-123733.yaml b/.changes/unreleased/Features-20230915-123733.yaml new file mode 100644 index 00000000000..146ad8ef89a --- /dev/null +++ b/.changes/unreleased/Features-20230915-123733.yaml @@ -0,0 +1,6 @@ +kind: Features +body: 'Allow adapters to include package logs in dbt standard logging ' +time: 2023-09-15T12:37:33.862862-07:00 +custom: + Author: colin-rogers-dbt + Issue: "7859" From 969bcfce2ceacd4e0cc5286b5d77f3d315e40533 Mon Sep 17 00:00:00 2001 From: Colin Date: Fri, 15 Sep 2023 16:26:14 -0700 Subject: [PATCH 12/14] swap function for dict --- core/dbt/events/event_handler.py | 23 ++++++++--------------- 1 file changed, 8 insertions(+), 15 deletions(-) diff --git a/core/dbt/events/event_handler.py b/core/dbt/events/event_handler.py index 6c79bf652f9..c74c7d232d9 100644 --- a/core/dbt/events/event_handler.py +++ b/core/dbt/events/event_handler.py @@ -6,20 +6,13 @@ from dbt.events.eventmgr import IEventManager - -def log_level_to_event_level(log_level: int) -> EventLevel: - if log_level == logging.DEBUG: - return EventLevel.DEBUG - elif log_level == logging.INFO: - return EventLevel.INFO - elif log_level == logging.WARNING: - return EventLevel.WARN - elif log_level == logging.ERROR: - return EventLevel.ERROR - elif log_level == logging.CRITICAL: - return EventLevel.ERROR - else: - return EventLevel.DEBUG +_log_level_to_event_level_map = { + logging.DEBUG: EventLevel.DEBUG, + logging.INFO: EventLevel.INFO, + logging.WARNING: EventLevel.WARN, + logging.ERROR: EventLevel.ERROR, + logging.CRITICAL: EventLevel.ERROR, +} class DbtEventLoggingHandler(logging.Handler): @@ -34,7 +27,7 @@ def __init__(self, event_manager: IEventManager, level=logging.NOTSET): def emit(self, record: logging.LogRecord): note = Note(msg=record.getMessage()) - level = log_level_to_event_level(record.levelno) + level = _log_level_to_event_level_map[record.levelno] self.event_manager.fire_event(e=note, level=level) From 1cf2e06f42b4984f74534e5a559632266ef50d5f Mon Sep 17 00:00:00 2001 From: Colin Date: Fri, 15 Sep 2023 16:43:22 -0700 Subject: [PATCH 13/14] add additional unit tests --- core/dbt/events/adapter_endpoint.py | 2 +- core/dbt/events/event_handler.py | 3 ++- tests/unit/test_event_handler.py | 15 ++++++++++++++- tests/unit/test_events.py | 7 +++++++ 4 files changed, 24 insertions(+), 3 deletions(-) diff --git a/core/dbt/events/adapter_endpoint.py b/core/dbt/events/adapter_endpoint.py index 56a83a41e4d..933d6aa61ae 100644 --- a/core/dbt/events/adapter_endpoint.py +++ b/core/dbt/events/adapter_endpoint.py @@ -60,7 +60,7 @@ def critical(self, msg, *args): @staticmethod def set_adapter_dependency_log_level(package_name, level): - """By default dbt suppresses non-dbt package logs. This method allows + """By default, dbt suppresses non-dbt package logs. This method allows you to set the log level for a specific package. """ set_package_logging(package_name, level, EVENT_MANAGER) diff --git a/core/dbt/events/event_handler.py b/core/dbt/events/event_handler.py index c74c7d232d9..4a1731a6f58 100644 --- a/core/dbt/events/event_handler.py +++ b/core/dbt/events/event_handler.py @@ -9,6 +9,7 @@ _log_level_to_event_level_map = { logging.DEBUG: EventLevel.DEBUG, logging.INFO: EventLevel.INFO, + logging.WARN: EventLevel.WARN, logging.WARNING: EventLevel.WARN, logging.ERROR: EventLevel.ERROR, logging.CRITICAL: EventLevel.ERROR, @@ -21,7 +22,7 @@ class DbtEventLoggingHandler(logging.Handler): All logs are generated as "Note" events. """ - def __init__(self, event_manager: IEventManager, level=logging.NOTSET): + def __init__(self, event_manager: IEventManager, level): super().__init__(level) self.event_manager = event_manager diff --git a/tests/unit/test_event_handler.py b/tests/unit/test_event_handler.py index 482add83046..e5ec49966ce 100644 --- a/tests/unit/test_event_handler.py +++ b/tests/unit/test_event_handler.py @@ -1,7 +1,7 @@ import logging from dbt.events.base_types import EventLevel -from dbt.events.event_handler import DbtEventLoggingHandler +from dbt.events.event_handler import DbtEventLoggingHandler, set_package_logging from dbt.events.eventmgr import TestEventManager @@ -25,3 +25,16 @@ def test_event_logging_handler_emits_records_correctly(): assert event_manager.event_history[3][1] == EventLevel.ERROR assert event_manager.event_history[4][1] == EventLevel.ERROR assert event_manager.event_history[5][1] == EventLevel.ERROR + + +def test_set_package_logging_sets_level_correctly(): + event_manager = TestEventManager() + log = logging.getLogger("test") + set_package_logging("test", logging.DEBUG, event_manager) + log.debug("debug") + assert len(event_manager.event_history) == 1 + set_package_logging("test", logging.WARN, event_manager) + log.debug("debug 2") + assert len(event_manager.event_history) == 1 + log.warning("warning") + assert len(event_manager.event_history) == 3 # warning logs create two events diff --git a/tests/unit/test_events.py b/tests/unit/test_events.py index 8c93381c938..64e24429965 100644 --- a/tests/unit/test_events.py +++ b/tests/unit/test_events.py @@ -1,3 +1,4 @@ +import logging import re from argparse import Namespace from typing import TypeVar @@ -83,6 +84,12 @@ def test_formatting(self): event = types.JinjaLogDebug(msg=[1, 2, 3]) assert isinstance(event.msg, str) + def test_set_adapter_dependency_log_level(self): + logger = AdapterLogger("dbt_tests") + package_log = logging.getLogger("test_package_log") + logger.set_adapter_dependency_log_level("test_package_log", "DEBUG") + package_log.debug("debug message") + class TestEventCodes: From 8418518896f25b9e863911d677f4a1a955a24a35 Mon Sep 17 00:00:00 2001 From: Colin Date: Mon, 18 Sep 2023 09:30:51 -0700 Subject: [PATCH 14/14] fix unit test --- tests/unit/test_event_handler.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/unit/test_event_handler.py b/tests/unit/test_event_handler.py index e5ec49966ce..905b23f5a11 100644 --- a/tests/unit/test_event_handler.py +++ b/tests/unit/test_event_handler.py @@ -7,7 +7,7 @@ def test_event_logging_handler_emits_records_correctly(): event_manager = TestEventManager() - handler = DbtEventLoggingHandler(event_manager=event_manager) + handler = DbtEventLoggingHandler(event_manager=event_manager, level=logging.DEBUG) log = logging.getLogger("test") log.setLevel(logging.DEBUG) log.addHandler(handler)