Merge pull request #7705 from jenshnielsen/jenshnielsen/trace_add_result_time

Track time spend in add_result

Author: jenshnielsen

src/qcodes/dataset/measurements.py

@@ -17,7 +17,7 @@
 from inspect import signature
 from itertools import chain
 from numbers import Number
-from time import perf_counter
+from time import perf_counter, perf_counter_ns
 from typing import TYPE_CHECKING, Any, TypeAlias, TypeVar, cast
 
 import numpy as np
@@ -67,6 +67,7 @@
 log = logging.getLogger(__name__)
 TRACER = trace.get_tracer(__name__)
 
+
 ActionType = tuple[Callable[..., Any], Sequence[Any]]
 SubscriberType = tuple[
     Callable[..., Any], MutableSequence[Any] | MutableMapping[Any, Any]
@@ -98,6 +99,7 @@ def __init__(
     ) -> None:
         self._span = span
         self._dataset = dataset
+        self._add_result_time_ns = 0
         if (
             DataSaver.default_callback is not None
             and "run_tables_subscription_callback" in DataSaver.default_callback
@@ -207,6 +209,7 @@ def add_result(self, *result_tuples: ResType) -> None:
                 its type.
 
         """
+        start_time = perf_counter_ns()
 
         parameter_results: list[ParameterResultType] = [
             self._coerce_result_tuple_to_parameter_result_type(result_tuple)
@@ -277,6 +280,7 @@ def add_result(self, *result_tuples: ResType) -> None:
         if perf_counter() - self._last_save_time > self.write_period:
             self.flush_data_to_database()
             self._last_save_time = perf_counter()
+        self._add_result_time_ns += perf_counter_ns() - start_time
 
     def _unpack_arrayparameter(
         self, partial_result: ResType
@@ -734,6 +738,8 @@ def __exit__(
         with DelayedKeyboardInterrupt(
             context={"reason": "qcodes measurement exit", "qcodes_guid": self.ds.guid}
         ):
+            add_result_time = self.datasaver._add_result_time_ns
+            self._span.set_attribute("qcodes_add_result_time_ms", add_result_time / 1e6)
             self.datasaver.flush_data_to_database(block=True)
 
             # perform the "teardown" events