instrument NADE commands using metric spans

src/snowflake/cli/api/metrics.py

@@ -109,10 +109,8 @@ class for holding metrics span data and encapsulating related operations
     children: Set[CLIMetricsSpan] = field(init=False, default_factory=set)
 
     # private state
-    # start time of the step from the monotonic clock in order to calculate execution time
-    _monotonic_start: float = field(
-        init=False, default_factory=lambda: time.monotonic()
-    )
+    # start time of the step from a performance counter in order to calculate execution time
+    _start_time: float = field(init=False, default_factory=time.perf_counter)
 
     def __hash__(self) -> int:
         return hash(self.span_id)
@@ -147,7 +145,7 @@ def finish(self, error: Optional[BaseException] = None) -> None:
         if error:
             self.error = error
 
-        self.execution_time = time.monotonic() - self._monotonic_start
+        self.execution_time = time.perf_counter() - self._start_time
 
     def to_dict(self) -> Dict:
         """
@@ -184,9 +182,10 @@ class CLIMetrics:
     _in_progress_spans: List[CLIMetricsSpan] = field(init=False, default_factory=list)
     # list of finished steps for telemetry to process
     _completed_spans: List[CLIMetricsSpan] = field(init=False, default_factory=list)
-    # monotonic clock time of when this class was initialized to approximate when the command first started executing
-    _monotonic_start: float = field(
-        init=False, default_factory=lambda: time.monotonic(), compare=False
+    # clock time of a performance counter when this class was initialized
+    # to approximate when the command first started executing
+    _start_time: float = field(
+        init=False, default_factory=time.perf_counter, compare=False
     )
 
     def clone(self) -> CLIMetrics:
@@ -229,7 +228,7 @@ def span(self, name: str) -> Iterator[CLIMetricsSpan]:
         """
         new_span = CLIMetricsSpan(
             name=name,
-            start_time=time.monotonic() - self._monotonic_start,
+            start_time=time.perf_counter() - self._start_time,
             parent=self.current_span,
         )
 

tests/api/test_metrics.py

@@ -14,7 +14,6 @@
 
 import uuid
 from itertools import count
-from unittest import mock
 
 import pytest
 from snowflake.cli.api.metrics import (
@@ -110,14 +109,6 @@ def test_metrics_set_default_existing_counter():
     assert metrics.counters == {"c2": 2}
 
 
-# we need to mock time.monotonic because on windows it does not
-# capture enough precision for these tests to not be flaky
-@pytest.fixture
-def mock_time_monotonic():
-    with mock.patch("time.monotonic", side_effect=count()) as mocked_time_monotonic:
-        yield mocked_time_monotonic
-
-
 # helper for testing span limits
 def create_spans(metrics: CLIMetrics, width: int, depth: int):
     counter = count()
@@ -146,7 +137,7 @@ def test_metrics_spans_initialization_empty():
     assert metrics.num_spans_past_total_limit == 0
 
 
-def test_metrics_spans_single_span_no_error_or_parent(mock_time_monotonic):
+def test_metrics_spans_single_span_no_error_or_parent():
     # given
     metrics = CLIMetrics()
 
@@ -191,7 +182,7 @@ def test_metrics_spans_finish_early_is_idempotent():
     assert span1_dict[CLIMetricsSpan.EXECUTION_TIME_KEY] == execution_time
 
 
-def test_metrics_spans_parent_with_one_child(mock_time_monotonic):
+def test_metrics_spans_parent_with_one_child():
     # given
     metrics = CLIMetrics()
 
@@ -244,7 +235,7 @@ def test_metrics_spans_parent_with_one_child(mock_time_monotonic):
     )
 
 
-def test_metrics_spans_parent_with_two_children_same_name(mock_time_monotonic):
+def test_metrics_spans_parent_with_two_children_same_name():
     # given
     metrics = CLIMetrics()
 
@@ -358,9 +349,7 @@ def test_metrics_spans_empty_name_raises_error():
     assert err.match("span name must not be empty")
 
 
-def test_metrics_spans_passing_depth_limit_should_add_to_counter_and_not_emit(
-    mock_time_monotonic,
-):
+def test_metrics_spans_passing_depth_limit_should_add_to_counter_and_not_emit():
     # given
     metrics = CLIMetrics()