CT-2264, CT-2259, CT-1783: Improved event serialization failure handling

.changes/unreleased/Fixes-20230331-095428.yaml

@@ -0,0 +1,6 @@
+kind: Fixes
+body: Improved failed event serialization handling and associated tests
+time: 2023-03-31T09:54:28.701963-07:00
+custom:
+  Author: QMalcolm
+  Issue: 7113 7108 6568

core/dbt/events/base_types.py

@@ -79,7 +79,7 @@ def __init__(self, *args, **kwargs):
             if "pytest" in sys.modules:
                 raise Exception(error_msg)
             else:
-                fire_event(Note(msg=error_msg))
+                fire_event(Note(msg=error_msg), level=EventLevel.WARN)
                 self.pb_msg = msg_cls()
 
     def __setattr__(self, key, value):

core/dbt/events/functions.py

@@ -2,7 +2,7 @@
 from dbt.events.base_types import BaseEvent, EventLevel, EventMsg
 from dbt.events.eventmgr import EventManager, LoggerConfig, LineFormat, NoFilter
 from dbt.events.helpers import env_secrets, scrub_secrets
-from dbt.events.types import Formatting
+from dbt.events.types import Formatting, Note
 from dbt.flags import get_flags, ENABLE_LEGACY_LOGGER
 from dbt.logger import GLOBAL_LOGGER, make_log_dir_if_missing
 from functools import partial
@@ -219,7 +219,9 @@ def msg_to_dict(msg: EventMsg) -> dict:
         )
     except Exception as exc:
         event_type = type(msg).__name__
-        raise Exception(f"type {event_type} is not serializable. {str(exc)}")
+        fire_event(
+            Note(msg=f"type {event_type} is not serializable. {str(exc)}"), level=EventLevel.WARN
+        )
     # We don't want an empty NodeInfo in output
     if (
         "data" in msg_dict

tests/unit/test_base_context.py

@@ -0,0 +1,22 @@
+import os
+
+from dbt.context.base import BaseContext
+from jinja2.runtime import Undefined
+
+
+class TestBaseContext:
+    def test_log_jinja_undefined(self):
+        # regression test for CT-2259
+        try:
+            os.environ["DBT_ENV_SECRET_LOG_TEST"] = "cats_are_cool"
+            BaseContext.log(msg=Undefined(), info=True)
+        except Exception as e:
+            assert False, f"Logging an jinja2.Undefined object raises an exception: {e}"
+
+    def test_log_with_dbt_env_secret(self):
+        # regression test for CT-1783
+        try:
+            os.environ["DBT_ENV_SECRET_LOG_TEST"] = "cats_are_cool"
+            BaseContext.log({"fact1": "I like cats"}, info=True)
+        except Exception as e:
+            assert False, f"Logging while a `DBT_ENV_SECRET` was set raised an exception: {e}"

tests/unit/test_events.py

@@ -1,3 +1,4 @@
+import pytest
 import re
 from typing import TypeVar
 
@@ -442,3 +443,21 @@ def test_date_serialization():
     ti_dict = ti.to_dict()
     assert ti_dict["started_at"].endswith("Z")
     assert ti_dict["completed_at"].endswith("Z")
+
+
+def test_bad_serialization():
+    """Tests that bad serialization enters the proper exception handling
+
+    When pytest is in use the exception handling of `BaseEvent` raises an
+    exception. When pytest isn't present, it fires a Note event. Thus to test
+    that bad serializations are properly handled, the best we can do is test
+    that the exception handling path is used.
+    """
+
+    with pytest.raises(Exception) as excinfo:
+        types.Note(param_event_doesnt_have="This should break")
+
+    assert (
+        str(excinfo.value)
+        == "[Note]: Unable to parse dict {'param_event_doesnt_have': 'This should break'}"
+    )

tests/unit/test_functions.py

@@ -2,8 +2,8 @@
 import pytest
 
 import dbt.flags as flags
-from dbt.events.functions import warn_or_error
-from dbt.events.types import NoNodesForSelectionCriteria
+from dbt.events.functions import msg_to_dict, warn_or_error
+from dbt.events.types import InfoLevel, NoNodesForSelectionCriteria
 from dbt.exceptions import EventCompilationError
 
 
@@ -43,3 +43,19 @@ def test_warn_or_error_warn_error(warn_error, expect_compilation_exception):
             warn_or_error(NoNodesForSelectionCriteria())
     else:
         warn_or_error(NoNodesForSelectionCriteria())
+
+
+def test_msg_to_dict_handles_exceptions_gracefully():
+    class BadEvent(InfoLevel):
+        """A spoof Note event which breaks dictification"""
+
+        def __init__(self):
+            self.__class__.__name__ = "Note"
+
+    event = BadEvent()
+    try:
+        msg_to_dict(event)
+    except Exception as exc:
+        assert (
+            False
+        ), f"We expect `msg_to_dict` to gracefully handle exceptions, but it raised {exc}"