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" diff --git a/core/dbt/events/adapter_endpoint.py b/core/dbt/events/adapter_endpoint.py index 0b780d05ae0..938af608b72 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 +from dbt.events.functions import fire_event, EVENT_MANAGER from dbt.events.contextvars import get_node_info +from dbt.events.event_handler import set_package_logging from dbt.events.types import ( AdapterEventDebug, AdapterEventInfo, @@ -56,3 +57,10 @@ def critical(self, msg, *args) -> None: 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): + """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 new file mode 100644 index 00000000000..4a1731a6f58 --- /dev/null +++ b/core/dbt/events/event_handler.py @@ -0,0 +1,40 @@ +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 + +_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, +} + + +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): + super().__init__(level) + self.event_manager = event_manager + + def emit(self, record: logging.LogRecord): + note = Note(msg=record.getMessage()) + level = _log_level_to_event_level_map[record.levelno] + self.event_manager.fire_event(e=note, level=level) + + +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(log_level) + event_handler = DbtEventLoggingHandler(event_manager=event_mgr, level=log_level) + log.addHandler(event_handler) diff --git a/core/dbt/events/functions.py b/core/dbt/events/functions.py index 0aa2f50a774..bfb1fda5a39 100644 --- a/core/dbt/events/functions.py +++ b/core/dbt/events/functions.py @@ -95,7 +95,6 @@ def _get_stdout_config( level: EventLevel, log_cache_events: bool, ) -> LoggerConfig: - return LoggerConfig( name="stdout_log", level=level, @@ -127,6 +126,7 @@ def _get_logfile_config( level: EventLevel, log_file_max_bytes: int, ) -> LoggerConfig: + return LoggerConfig( name="file_log", line_format=line_format, diff --git a/tests/unit/test_event_handler.py b/tests/unit/test_event_handler.py new file mode 100644 index 00000000000..905b23f5a11 --- /dev/null +++ b/tests/unit/test_event_handler.py @@ -0,0 +1,40 @@ +import logging + +from dbt.events.base_types import EventLevel +from dbt.events.event_handler import DbtEventLoggingHandler, set_package_logging +from dbt.events.eventmgr import TestEventManager + + +def test_event_logging_handler_emits_records_correctly(): + event_manager = TestEventManager() + handler = DbtEventLoggingHandler(event_manager=event_manager, level=logging.DEBUG) + 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 + + +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: