Measure the performance in launchable record tests command

Author: ono-max

launchable/commands/helper.py

@@ -1,3 +1,4 @@
+from time import time
 from typing import Optional, Sequence, Tuple
 
 import click
@@ -137,6 +138,12 @@ def find_or_create_session(
     return read_session(saved_build_name)
 
 
+def time_ns():
+    # time.time_ns() method is new in Python version 3.7
+    # As a workaround, we convert time.time() to nanoseconds.
+    return int(time() * 1e9)
+
+
 def _check_observation_mode_status(session: str, is_observation: bool,
                                    tracking_client: TrackingClient, app: Optional[Application] = None):
     if not is_observation:

launchable/commands/record/tests.py

@@ -22,7 +22,7 @@
 from ...utils.logger import Logger
 from ...utils.no_build import NO_BUILD_BUILD_NAME, NO_BUILD_TEST_SESSION_ID
 from ...utils.session import parse_session, read_build
-from ..helper import find_or_create_session
+from ..helper import find_or_create_session, time_ns
 from .case_event import CaseEvent, CaseEventType
 
 GROUP_NAME_RULE = re.compile("^[a-zA-Z0-9][a-zA-Z0-9_-]*$")
@@ -535,14 +535,24 @@ def recorded_result() -> Tuple[int, int, int, float]:
                 return test_count, success_count, fail_count, duration / 60   # sec to min
 
             try:
+                start = time_ns()
                 tc = testcases(self.reports)
+                end = time_ns()
+                tracking_client.send_event(
+                    event_name=Tracking.Event.PERFORMANCE,
+                    metadata={
+                        "elapsedTime": end - start,
+                        "measurementTarget": "testcases method(parsing report file)"
+                    }
+                )
 
                 if report_paths:
                     # diagnostics mode to just report test paths
                     for t in tc:
                         print(unparse_test_path(t['testPath']))
                     return
 
+                start = time_ns()
                 exceptions = []
                 for chunk in ichunked(tc, post_chunk):
                     p, es = payload(
@@ -555,6 +565,14 @@ def recorded_result() -> Tuple[int, int, int, float]:
 
                     send(p)
                     exceptions.extend(es)
+                end = time_ns()
+                tracking_client.send_event(
+                    event_name=Tracking.Event.PERFORMANCE,
+                    metadata={
+                        "elapsedTime": end - start,
+                        "measurementTarget": "events API"
+                    }
+                )
 
                 if len(exceptions) > 0:
                     raise Exception(exceptions)

launchable/utils/tracking.py

@@ -13,6 +13,7 @@ class Tracking:
     # General events
     class Event(Enum):
         SHALLOW_CLONE = 'SHALLOW_CLONE'  # this event is an example
+        PERFORMANCE = 'PERFORMANCE'
 
     # Error events
     class ErrorEvent(Enum):

tests/commands/test_api_error.py

@@ -451,7 +451,7 @@ def test_all_workflow_when_server_down(self):
         result = self.cli("record", "tests", "--session", self.session, "minitest", str(self.test_files_dir) + "/")
         self.assert_success(result)
         # Since Timeout error is caught inside of LaunchableClient, the tracking event is sent twice.
-        self.assert_tracking_count(tracking=tracking, count=8)
+        self.assert_tracking_count(tracking=tracking, count=9)
 
     def assert_tracking_count(self, tracking, count: int):
         # Prior to 3.6, `Response` object can't be obtained.