diff --git a/.changes/unreleased/Fixes-20230111-134058.yaml b/.changes/unreleased/Fixes-20230111-134058.yaml new file mode 100644 index 00000000000..707cbfb39c6 --- /dev/null +++ b/.changes/unreleased/Fixes-20230111-134058.yaml @@ -0,0 +1,6 @@ +kind: Fixes +body: Call update_event_status earlier for node results. Rename event 'HookFinished' -> FinishedRunningStats +time: 2023-01-11T13:40:58.577722+01:00 +custom: + Author: jtcohen6 + Issue: "6571" diff --git a/core/dbt/events/proto_types.py b/core/dbt/events/proto_types.py index 1fe552270bf..2fc6ad1ccd7 100644 --- a/core/dbt/events/proto_types.py +++ b/core/dbt/events/proto_types.py @@ -945,7 +945,7 @@ class HooksRunningMsg(betterproto.Message): @dataclass -class HookFinished(betterproto.Message): +class FinishedRunningStats(betterproto.Message): """E047""" stat_line: str = betterproto.string_field(1) @@ -954,9 +954,9 @@ class HookFinished(betterproto.Message): @dataclass -class HookFinishedMsg(betterproto.Message): +class FinishedRunningStatsMsg(betterproto.Message): info: "EventInfo" = betterproto.message_field(1) - data: "HookFinished" = betterproto.message_field(2) + data: "FinishedRunningStats" = betterproto.message_field(2) @dataclass diff --git a/core/dbt/events/types.proto b/core/dbt/events/types.proto index 80510687f81..21f9c9ee4bb 100644 --- a/core/dbt/events/types.proto +++ b/core/dbt/events/types.proto @@ -747,15 +747,15 @@ message HooksRunningMsg { } // E047 -message HookFinished { +message FinishedRunningStats { string stat_line = 1; string execution = 2; float execution_time = 3; } -message HookFinishedMsg { +message FinishedRunningStatsMsg { EventInfo info = 1; - HookFinished data = 2; + FinishedRunningStats data = 2; } diff --git a/core/dbt/events/types.py b/core/dbt/events/types.py index 83fdf7854c1..4a2a0fb99ee 100644 --- a/core/dbt/events/types.py +++ b/core/dbt/events/types.py @@ -755,7 +755,7 @@ def message(self) -> str: @dataclass -class HookFinished(InfoLevel, pt.HookFinished): +class FinishedRunningStats(InfoLevel, pt.FinishedRunningStats): def code(self): return "E047" diff --git a/core/dbt/task/base.py b/core/dbt/task/base.py index e13f963cc7b..63449de10c7 100644 --- a/core/dbt/task/base.py +++ b/core/dbt/task/base.py @@ -4,6 +4,7 @@ import traceback from abc import ABCMeta, abstractmethod from typing import Type, Union, Dict, Any, Optional +from datetime import datetime from dbt import tracking from dbt import flags @@ -208,6 +209,9 @@ def run_with_hooks(self, manifest): self.before_execute() result = self.safe_run(manifest) + self.node.update_event_status( + node_status=result.status, finished_at=datetime.utcnow().isoformat() + ) if not self.node.is_ephemeral_model: self.after_execute(result) @@ -448,6 +452,9 @@ def on_skip(self): ) ) else: + # 'skipped' nodes should not have a value for 'node_finished_at' + # they do have 'node_started_at', which is set in GraphRunnableTask.call_runner + self.node.update_event_status(node_status=RunStatus.Skipped) fire_event( SkippingDetails( resource_type=self.node.resource_type, diff --git a/core/dbt/task/run.py b/core/dbt/task/run.py index 145225be9d5..411c57af663 100644 --- a/core/dbt/task/run.py +++ b/core/dbt/task/run.py @@ -32,7 +32,7 @@ DatabaseErrorRunningHook, EmptyLine, HooksRunning, - HookFinished, + FinishedRunningStats, LogModelResult, LogStartLine, LogHookEndLine, @@ -421,7 +421,9 @@ def print_results_line(self, results, execution_time): with TextOnly(): fire_event(EmptyLine()) fire_event( - HookFinished(stat_line=stat_line, execution=execution, execution_time=execution_time) + FinishedRunningStats( + stat_line=stat_line, execution=execution, execution_time=execution_time + ) ) def before_run(self, adapter, selected_uids: AbstractSet[str]): diff --git a/core/dbt/task/runnable.py b/core/dbt/task/runnable.py index 0b4b47a7c5f..fee5fadc891 100644 --- a/core/dbt/task/runnable.py +++ b/core/dbt/task/runnable.py @@ -226,10 +226,6 @@ def call_runner(self, runner): status: Dict[str, str] = {} try: result = runner.run_with_hooks(self.manifest) - status = runner.get_result_status(result) - runner.node.update_event_status( - node_status=result.status, finished_at=datetime.utcnow().isoformat() - ) finally: finishctx = TimestampNamed("finished_at") with finishctx, DbtModelState(status): diff --git a/tests/unit/test_events.py b/tests/unit/test_events.py index 07f1fed2715..2afee427c4d 100644 --- a/tests/unit/test_events.py +++ b/tests/unit/test_events.py @@ -177,7 +177,7 @@ def test_event_codes(self): BuildingCatalog(), DatabaseErrorRunningHook(hook_type=""), HooksRunning(num_hooks=0, hook_type=""), - HookFinished(stat_line="", execution="", execution_time=0), + FinishedRunningStats(stat_line="", execution="", execution_time=0), # I - Project parsing ====================== ParseCmdOut(msg="testing"),