Include node_info in various Result events (#9820)

.changes/unreleased/Under the Hood-20240325-172059.yaml

@@ -0,0 +1,6 @@
+kind: Under the Hood
+body: Include node_info in various Result events
+time: 2024-03-25T17:20:59.445718-04:00
+custom:
+  Author: gshank
+  Issue: "9619"

core/dbt/events/core_types.proto

@@ -1772,6 +1772,7 @@ message RunResultWarning {
     string resource_type = 1;
     string node_name = 2;
     string path = 3;
+    NodeInfo node_info = 4;
 }
 
 message RunResultWarningMsg {
@@ -1784,6 +1785,7 @@ message RunResultFailure {
     string resource_type = 1;
     string node_name = 2;
     string path = 3;
+    NodeInfo node_info = 4;
 }
 
 message RunResultFailureMsg {
@@ -1804,6 +1806,7 @@ message StatsLineMsg {
 // Z024
 message RunResultError {
     string msg = 1;
+    NodeInfo node_info = 2;
 }
 
 message RunResultErrorMsg {
@@ -1814,6 +1817,7 @@ message RunResultErrorMsg {
 // Z025
 message RunResultErrorNoMessage {
     string status = 1;
+    NodeInfo node_info = 2;
 }
 
 message RunResultErrorNoMessageMsg {
@@ -1824,6 +1828,7 @@ message RunResultErrorNoMessageMsg {
 // Z026
 message SQLCompiledPath {
     string path = 1;
+    NodeInfo node_info = 2;
 }
 
 message SQLCompiledPathMsg {
@@ -1834,6 +1839,7 @@ message SQLCompiledPathMsg {
 // Z027
 message CheckNodeTestFailure {
     string relation_name = 1;
+    NodeInfo node_info = 2;
 }
 
 message CheckNodeTestFailureMsg {
@@ -1958,6 +1964,7 @@ message TrackingInitializeFailureMsg {
 // Z046
 message RunResultWarningMessage {
     string msg = 1;
+    NodeInfo node_info = 2;
 }
 
 message RunResultWarningMessageMsg {

core/dbt/task/printer.py

@@ -79,13 +79,18 @@ def print_run_result_error(result, newline: bool = True, is_warning: bool = Fals
         with TextOnly():
             fire_event(Formatting(""))
 
+    # set node_info for logging events
+    node_info = None
+    if hasattr(result, "node") and result.node:
+        node_info = result.node.node_info
     if result.status == NodeStatus.Fail or (is_warning and result.status == NodeStatus.Warn):
         if is_warning:
             fire_event(
                 RunResultWarning(
                     resource_type=result.node.resource_type,
                     node_name=result.node.name,
                     path=result.node.original_file_path,
+                    node_info=node_info,
                 )
             )
         else:
@@ -94,29 +99,32 @@ def print_run_result_error(result, newline: bool = True, is_warning: bool = Fals
                     resource_type=result.node.resource_type,
                     node_name=result.node.name,
                     path=result.node.original_file_path,
+                    node_info=node_info,
                 )
             )
 
         if result.message:
             if is_warning:
-                fire_event(RunResultWarningMessage(msg=result.message))
+                fire_event(RunResultWarningMessage(msg=result.message, node_info=node_info))
             else:
-                fire_event(RunResultError(msg=result.message))
+                fire_event(RunResultError(msg=result.message, node_info=node_info))
         else:
-            fire_event(RunResultErrorNoMessage(status=result.status))
+            fire_event(RunResultErrorNoMessage(status=result.status, node_info=node_info))
 
         if result.node.build_path is not None:
             with TextOnly():
                 fire_event(Formatting(""))
-            fire_event(SQLCompiledPath(path=result.node.compiled_path))
+            fire_event(SQLCompiledPath(path=result.node.compiled_path, node_info=node_info))
 
         if result.node.should_store_failures:
             with TextOnly():
                 fire_event(Formatting(""))
-            fire_event(CheckNodeTestFailure(relation_name=result.node.relation_name))
+            fire_event(
+                CheckNodeTestFailure(relation_name=result.node.relation_name, node_info=node_info)
+            )
 
     elif result.message is not None:
-        fire_event(RunResultError(msg=result.message))
+        fire_event(RunResultError(msg=result.message, node_info=node_info))
 
 
 def print_run_end_messages(results, keyboard_interrupt: bool = False) -> None:

core/dbt/task/runnable.py

@@ -51,7 +51,6 @@
     ModelMetadata,
     NodeCount,
 )
-from dbt.node_types import NodeType
 from dbt.parser.manifest import write_manifest
 from dbt.task.base import ConfiguredTask, BaseRunner
 from .printer import (
@@ -261,9 +260,8 @@ def call_runner(self, runner: BaseRunner) -> RunResult:
                         )
 
             # `_event_status` dict is only used for logging.  Make sure
-            # it gets deleted when we're done with it, except for unit tests
-            if not runner.node.resource_type == NodeType.Unit:
-                runner.node.clear_event_status()
+            # it gets deleted when we're done with it
+            runner.node.clear_event_status()
 
         fail_fast = get_flags().FAIL_FAST
 

tests/functional/logging/test_logging.py

@@ -100,3 +100,39 @@ def test_invalid_event_value(project, logs_dir):
         fire_event(InvalidOptionYAML(option_name=1))
 
     assert str(excinfo.value) == "[InvalidOptionYAML]: Unable to parse dict {'option_name': 1}"
+
+
+class TestNodeInfo:
+    @pytest.fixture(scope="class")
+    def models(self):
+        return {"my_model.sql": "select not_found as id"}
+
+    def test_node_info_on_results(self, project, logs_dir):
+        results = run_dbt(["--log-format=json", "run"], expect_pass=False)
+        assert len(results) == 1
+        # get log file
+        log_file = read_file(logs_dir, "dbt.log")
+        task_printer_events = [
+            "RunResultWarning",
+            "RunResultFailure",
+            "RunResultWarningMessage",
+            "RunResultError",
+            "RunResultErrorNoMessage",
+            "SQLCompiledPath",
+            "CheckNodeTestFailure",
+        ]
+        count = 0
+        for log_line in log_file.split("\n"):
+            # skip empty lines
+            if len(log_line) == 0:
+                continue
+            # The adapter logging also shows up, so skip non-json lines
+            if "[debug]" in log_line:
+                continue
+            log_dct = json.loads(log_line)
+            log_data = log_dct["data"]
+            log_event = log_dct["info"]["name"]
+            if log_event in task_printer_events:
+                assert "node_info" in log_data
+                count += 1
+        assert count > 0