CT-2049: Add CommandCompleted event

.changes/unreleased/Under the Hood-20230316-123305.yaml

@@ -0,0 +1,6 @@
+kind: Under the Hood
+body: Add CommandCompleted event, and fire it upon completion of every command
+time: 2023-03-16T12:33:05.696752-07:00
+custom:
+  Author: QMalcolm
+  Issue: "6878"

core/dbt/cli/requires.py

@@ -5,15 +5,22 @@
 from dbt.config import RuntimeConfig
 from dbt.config.runtime import load_project, load_profile, UnsetProfile
 from dbt.events.functions import setup_event_logger, fire_event, LOG_VERSION
-from dbt.events.types import MainReportVersion, MainReportArgs, MainTrackingUserState
+from dbt.events.types import (
+    CommandCompleted,
+    MainReportVersion,
+    MainReportArgs,
+    MainTrackingUserState,
+)
 from dbt.exceptions import DbtProjectError
 from dbt.parser.manifest import ManifestLoader, write_manifest
 from dbt.profiler import profiler
 from dbt.tracking import active_user, initialize_from_flags, track_run
 from dbt.utils import cast_dict_to_dict_of_strings
 
 from click import Context
+import datetime
 from functools import update_wrapper
+import time
 
 
 def preflight(func):
@@ -53,7 +60,33 @@ def wrapper(*args, **kwargs):
         # Adapter management
         ctx.with_resource(adapter_management())
 
-        return func(*args, **kwargs)
+        start_func = time.perf_counter()
+
+        try:
+            (results, success) = func(*args, **kwargs)
+
+            fire_event(
+                CommandCompleted(
+                    command=ctx.command_path,
+                    success=success,
+                    completed_at=datetime.datetime.utcnow(),
+                    elapsed=time.perf_counter() - start_func,
+                )
+            )
+        # Bare except because we really do want to catch ALL exceptions,
+        # i.e. we want to fire this event in ALL cases.
+        except:  # noqa
+            fire_event(
+                CommandCompleted(
+                    command=ctx.command_path,
+                    success=False,
+                    completed_at=datetime.datetime.utcnow(),
+                    elapsed=time.perf_counter() - start_func,
+                )
+            )
+            raise
+
+        return (results, success)
 
     return update_wrapper(wrapper, func)
 

core/dbt/events/types.proto

@@ -1747,6 +1747,19 @@ message NoNodesSelectedMsg {
     NoNodesSelected data = 2;
 }
 
+// Q039
+message CommandCompleted {
+    string command = 1;
+    bool success = 2;
+    google.protobuf.Timestamp completed_at = 3;
+    float elapsed = 4;
+}
+
+message CommandCompletedMsg {
+    EventInfo info = 1;
+    CommandCompleted data = 2;
+}
+
 // W - Node testing
 
 // Skipped W001

core/dbt/events/types.py

@@ -1827,6 +1827,16 @@ def message(self) -> str:
         return "No nodes selected!"
 
 
+@dataclass
+class CommandCompleted(DebugLevel, pt.CommandCompleted):
+    def code(self):
+        return "Q039"
+
+    def message(self) -> str:
+        status = "succeeded" if self.success else "failed"
+        return f"Command `{self.command}` {status} at {self.completed_at} after {self.elapsed:0.2f} seconds"
+
+
 # =======================================================
 # W - Node testing
 # =======================================================

tests/unit/test_events.py

@@ -1,6 +1,7 @@
 import re
 from typing import TypeVar
 
+from datetime import datetime
 from dbt.contracts.results import TimingInfo
 from dbt.events import AdapterLogger, test_types, types
 from dbt.events.base_types import (
@@ -326,6 +327,7 @@ def test_event_codes(self):
     types.NoNodesSelected(),
     types.DepsUnpinned(revision="", git=""),
     types.NoNodesForSelectionCriteria(spec_raw=""),
+    types.CommandCompleted(command="", success=True, elapsed=0.1, completed_at=datetime.utcnow()),
     # W - Node testing ======================
     types.CatchableExceptionOnRun(exc=""),
     types.InternalErrorOnRun(build_path="", exc=""),