From 7fcca8523f1a245546c31be7d20d34f74e118e2d Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Tue, 7 Jun 2022 11:05:51 -0700 Subject: [PATCH 01/23] Add project metadata tracking with telemetry (#3929) * Implement project metadata metrics * Implement metric metadata integration tests * Tweak methods so tests don't fail on Linux machines * Repair failing integration test * Implement proper exception handling for subprocesses * Format according to standard * Refactor function names and encryption logic * Remove unnecessary file * Add type hints to new functions --- samcli/lib/telemetry/metric.py | 8 +- samcli/lib/telemetry/project_metadata.py | 110 +++++++++++++++++ .../telemetry/test_experimental_metric.py | 14 ++- tests/unit/lib/telemetry/test_metric.py | 1 + .../lib/telemetry/test_project_metadata.py | 111 ++++++++++++++++++ 5 files changed, 241 insertions(+), 3 deletions(-) create mode 100644 samcli/lib/telemetry/project_metadata.py create mode 100644 tests/unit/lib/telemetry/test_project_metadata.py diff --git a/samcli/lib/telemetry/metric.py b/samcli/lib/telemetry/metric.py index f6336e2ddd..8fc803fba1 100644 --- a/samcli/lib/telemetry/metric.py +++ b/samcli/lib/telemetry/metric.py @@ -17,6 +17,7 @@ from samcli.lib.warnings.sam_cli_warning import TemplateWarningsChecker from samcli.commands.exceptions import UserException from samcli.lib.telemetry.cicd import CICDDetector, CICDPlatform +from samcli.lib.telemetry.project_metadata import get_git_remote_origin_url, get_project_name, get_initial_commit_hash from samcli.commands._utils.experimental import get_all_experimental_statues from .telemetry import Telemetry from ..iac.cdk.utils import is_cdk_project @@ -153,8 +154,11 @@ def wrapped(*args, **kwargs): metric.add_data("debugFlagProvided", bool(ctx.debug)) metric.add_data("region", ctx.region or "") metric.add_data("commandName", ctx.command_path) # Full command path. ex: sam local start-api - if metric_specific_attributes: - metric.add_data("metricSpecificAttributes", metric_specific_attributes) + # Project metadata metrics + metric_specific_attributes["gitOrigin"] = get_git_remote_origin_url() + metric_specific_attributes["projectName"] = get_project_name() + metric_specific_attributes["initialCommit"] = get_initial_commit_hash() + metric.add_data("metricSpecificAttributes", metric_specific_attributes) # Metric about command's execution characteristics metric.add_data("duration", duration_fn()) metric.add_data("exitReason", exit_reason) diff --git a/samcli/lib/telemetry/project_metadata.py b/samcli/lib/telemetry/project_metadata.py new file mode 100644 index 0000000000..9536108501 --- /dev/null +++ b/samcli/lib/telemetry/project_metadata.py @@ -0,0 +1,110 @@ +""" +Creates and encrypts metadata regarding SAM CLI projects. +""" + +from os import getcwd +from os.path import basename +import re +import subprocess +from typing import List, Optional +from uuid import uuid5, NAMESPACE_URL + +from samcli.cli.global_config import GlobalConfig + + +def get_git_remote_origin_url() -> Optional[str]: + """ + Retrieve an encrypted version of the project's git remote origin url, if it exists. + + Returns + ------- + str | None + A UUID5 encrypted string of the git remote origin url, formatted such that the + encrypted value follows the pattern //.git. + If telemetry is opted out of by the user, or the `.git` folder is not found + (the directory is not a git repository), returns None + """ + if not bool(GlobalConfig().telemetry_enabled): + return None + + git_url = None + try: + runcmd = subprocess.run( + ["git", "config", "--get", "remote.origin.url"], capture_output=True, shell=True, check=True, text=True + ) + metadata = _parse_remote_origin_url(str(runcmd.stdout)) + git_url = "/".join(metadata) + ".git" # Format to //.git + except subprocess.CalledProcessError: + return None # Not a git repo + + return _encrypt_value(git_url) + + +def get_project_name() -> Optional[str]: + """ + Retrieve an encrypted version of the project's name, as defined by the .git folder (or directory name if no .git). + + Returns + ------- + str | None + A UUID5 encrypted string of either the name of the project, or the name of the + current directory that the command is running in. + If telemetry is opted out of by the user, returns None + """ + if not bool(GlobalConfig().telemetry_enabled): + return None + + project_name = "" + try: + runcmd = subprocess.run( + ["git", "config", "--get", "remote.origin.url"], capture_output=True, shell=True, check=True, text=True + ) + project_name = _parse_remote_origin_url(str(runcmd.stdout))[2] # dir is git repo, get project name from URL + except subprocess.CalledProcessError: + project_name = basename(getcwd().replace("\\", "/")) # dir is not a git repo, get directory name + + return _encrypt_value(project_name) + + +def get_initial_commit_hash() -> Optional[str]: + """ + Retrieve an encrypted version of the project's initial commit hash, if it exists. + + Returns + ------- + str | None + A UUID5 encrypted string of the git project's initial commit hash. + If telemetry is opted out of by the user, or the `.git` folder is not found + (the directory is not a git repository), returns None. + """ + if not bool(GlobalConfig().telemetry_enabled): + return None + + metadata = None + try: + runcmd = subprocess.run( + ["git", "rev-list", "--max-parents=0", "HEAD"], capture_output=True, shell=True, check=True, text=True + ) + metadata = runcmd.stdout.strip() + except subprocess.CalledProcessError: + return None # Not a git repo + + return _encrypt_value(metadata) + + +def _parse_remote_origin_url(url: str) -> List[str]: + """ + Parse a `git remote origin url` into its hostname, owner, and project name. + + Returns + ------- + List[str] + A list of 3 strings, with indeces corresponding to 0:hostname, 1:owner, 2:project_name + """ + pattern = re.compile(r"(?:https?://|git@)(?P\S*)(?:/|:)(?P\S*)/(?P\S*)\.git") + return [str(item) for item in pattern.findall(url)[0]] + + +def _encrypt_value(value: str) -> str: + """Encrypt a string, and then return the encrypted value as a string.""" + return str(uuid5(NAMESPACE_URL, value)) diff --git a/tests/integration/telemetry/test_experimental_metric.py b/tests/integration/telemetry/test_experimental_metric.py index 4d9a4f2fee..2bcd93e340 100644 --- a/tests/integration/telemetry/test_experimental_metric.py +++ b/tests/integration/telemetry/test_experimental_metric.py @@ -56,6 +56,9 @@ def test_must_send_experimental_metrics_if_experimental_command(self): "experimentalAccelerate": True, "experimentalAll": False, "experimentalEsbuild": False, + "gitOrigin": ANY, + "projectName": ANY, + "initialCommit": ANY, }, "duration": ANY, "exitReason": ANY, @@ -107,6 +110,9 @@ def test_must_send_experimental_metrics_if_experimental_option(self): "experimentalAccelerate": True, "experimentalAll": True, "experimentalEsbuild": True, + "gitOrigin": ANY, + "projectName": ANY, + "initialCommit": ANY, }, "duration": ANY, "exitReason": ANY, @@ -164,7 +170,12 @@ def test_must_send_cdk_project_type_metrics(self): "debugFlagProvided": ANY, "region": ANY, "commandName": ANY, - "metricSpecificAttributes": {"projectType": "CDK"}, + "metricSpecificAttributes": { + "projectType": "CDK", + "gitOrigin": ANY, + "projectName": ANY, + "initialCommit": ANY, + }, "duration": ANY, "exitReason": ANY, "exitCode": ANY, @@ -210,6 +221,7 @@ def test_must_send_not_experimental_metrics_if_not_experimental(self): "debugFlagProvided": ANY, "region": ANY, "commandName": ANY, + "metricSpecificAttributes": ANY, "duration": ANY, "exitReason": ANY, "exitCode": ANY, diff --git a/tests/unit/lib/telemetry/test_metric.py b/tests/unit/lib/telemetry/test_metric.py index 3cfc680a2e..e4b59fd6ec 100644 --- a/tests/unit/lib/telemetry/test_metric.py +++ b/tests/unit/lib/telemetry/test_metric.py @@ -181,6 +181,7 @@ def real_fn(): "debugFlagProvided": False, "region": "myregion", "commandName": "fakesam local invoke", + "metricSpecificAttributes": ANY, "duration": ANY, "exitReason": "success", "exitCode": 0, diff --git a/tests/unit/lib/telemetry/test_project_metadata.py b/tests/unit/lib/telemetry/test_project_metadata.py new file mode 100644 index 0000000000..acafd73562 --- /dev/null +++ b/tests/unit/lib/telemetry/test_project_metadata.py @@ -0,0 +1,111 @@ +""" +Module for testing the project_metadata.py methods. +""" + +from subprocess import CompletedProcess, CalledProcessError +from uuid import uuid5, NAMESPACE_URL +from unittest.mock import patch, Mock +from unittest import TestCase + +from parameterized import parameterized + +from samcli.lib.telemetry.project_metadata import get_git_remote_origin_url, get_project_name, get_initial_commit_hash + + +class TestProjectMetadata(TestCase): + def setUp(self): + self.gc_mock = Mock() + self.global_config_patcher = patch("samcli.lib.telemetry.project_metadata.GlobalConfig", self.gc_mock) + self.global_config_patcher.start() + self.gc_mock.return_value.telemetry_enabled = True + + def tearDown(self): + self.global_config_patcher.stop() + + def test_return_none_when_telemetry_disabled(self): + self.gc_mock.return_value.telemetry_enabled = False + + git_origin = get_git_remote_origin_url() + self.assertIsNone(git_origin) + + project_name = get_project_name() + self.assertIsNone(project_name) + + initial_commit = get_initial_commit_hash() + self.assertIsNone(initial_commit) + + @parameterized.expand( + [ + ("https://github.com/aws/aws-sam-cli.git\n", "github.com/aws/aws-sam-cli.git"), + ("http://github.com/aws/aws-sam-cli.git\n", "github.com/aws/aws-sam-cli.git"), + ("git@github.com:aws/aws-sam-cli.git\n", "github.com/aws/aws-sam-cli.git"), + ("https://github.com/aws/aws-cli.git\n", "github.com/aws/aws-cli.git"), + ("http://not.a.real.site.com/somebody/my-project.git", "not.a.real.site.com/somebody/my-project.git"), + ("git@not.github:person/my-project.git", "not.github/person/my-project.git"), + ] + ) + @patch("samcli.lib.telemetry.project_metadata.subprocess.run") + def test_retrieve_git_origin(self, origin, expected, sp_mock): + sp_mock.return_value = CompletedProcess(["git", "config", "--get", "remote.origin.url"], 0, stdout=origin) + + git_origin = get_git_remote_origin_url() + self.assertEqual(git_origin, str(uuid5(NAMESPACE_URL, expected))) + + @patch("samcli.lib.telemetry.project_metadata.subprocess.run") + def test_retrieve_git_origin_when_not_a_repo(self, sp_mock): + sp_mock.side_effect = CalledProcessError(128, ["git", "config", "--get", "remote.origin.url"]) + + git_origin = get_git_remote_origin_url() + self.assertIsNone(git_origin) + + @parameterized.expand( + [ + ("https://github.com/aws/aws-sam-cli.git\n", "aws-sam-cli"), + ("https://github.com/aws/aws-sam-cli.git\n", "aws-sam-cli"), + ("git@github.com:aws/aws-sam-cli.git\n", "aws-sam-cli"), + ("https://github.com/aws/aws-cli.git\n", "aws-cli"), + ("http://not.a.real.site.com/somebody/my-project.git", "my-project"), + ("git@not.github:person/my-project.git", "my-project"), + ] + ) + @patch("samcli.lib.telemetry.project_metadata.subprocess.run") + def test_retrieve_project_name_from_git(self, origin, expected, sp_mock): + sp_mock.return_value = CompletedProcess(["git", "config", "--get", "remote.origin.url"], 0, stdout=origin) + + project_name = get_project_name() + self.assertEqual(project_name, str(uuid5(NAMESPACE_URL, expected))) + + @parameterized.expand( + [ + ("C:/Users/aws/path/to/library/aws-sam-cli", "aws-sam-cli"), + ("C:\\Users\\aws\\Windows\\path\\aws-sam-cli", "aws-sam-cli"), + ("C:/", ""), + ("C:\\", ""), + ("E:/path/to/another/dir", "dir"), + ("This/one/doesn't/start/with/a/letter", "letter"), + ("/banana", "banana"), + ("D:/one/more/just/to/be/safe", "safe"), + ] + ) + @patch("samcli.lib.telemetry.project_metadata.getcwd") + @patch("samcli.lib.telemetry.project_metadata.subprocess.run") + def test_retrieve_project_name_from_dir(self, cwd, expected, sp_mock, cwd_mock): + sp_mock.side_effect = CalledProcessError(128, ["git", "config", "--get", "remote.origin.url"]) + cwd_mock.return_value = cwd + + project_name = get_project_name() + self.assertEqual(project_name, str(uuid5(NAMESPACE_URL, expected))) + + @parameterized.expand( + [ + ("0000000000000000000000000000000000000000"), + ("0123456789abcdef0123456789abcdef01234567"), + ("abababababababababababababababababababab"), + ] + ) + @patch("samcli.lib.telemetry.project_metadata.subprocess.run") + def test_retrieve_initial_commit(self, git_hash, sp_mock): + sp_mock.return_value = CompletedProcess(["git", "rev-list", "--max-parents=0", "HEAD"], 0, stdout=git_hash) + + initial_commit = get_initial_commit_hash() + self.assertEqual(initial_commit, str(uuid5(NAMESPACE_URL, git_hash))) From 91a0905446d45bf2f6ba491a7b5524714ca5a62e Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Mon, 13 Jun 2022 11:08:02 -0700 Subject: [PATCH 02/23] Fix retrieval process for directory name (#3962) --- samcli/lib/telemetry/project_metadata.py | 5 ++--- .../lib/telemetry/test_project_metadata.py | 20 +++++++++---------- 2 files changed, 12 insertions(+), 13 deletions(-) diff --git a/samcli/lib/telemetry/project_metadata.py b/samcli/lib/telemetry/project_metadata.py index 9536108501..ac5818e737 100644 --- a/samcli/lib/telemetry/project_metadata.py +++ b/samcli/lib/telemetry/project_metadata.py @@ -3,7 +3,6 @@ """ from os import getcwd -from os.path import basename import re import subprocess from typing import List, Optional @@ -48,7 +47,7 @@ def get_project_name() -> Optional[str]: ------- str | None A UUID5 encrypted string of either the name of the project, or the name of the - current directory that the command is running in. + current working directory that the command is running in. If telemetry is opted out of by the user, returns None """ if not bool(GlobalConfig().telemetry_enabled): @@ -61,7 +60,7 @@ def get_project_name() -> Optional[str]: ) project_name = _parse_remote_origin_url(str(runcmd.stdout))[2] # dir is git repo, get project name from URL except subprocess.CalledProcessError: - project_name = basename(getcwd().replace("\\", "/")) # dir is not a git repo, get directory name + project_name = getcwd().replace("\\", "/") # dir is not a git repo, get directory name return _encrypt_value(project_name) diff --git a/tests/unit/lib/telemetry/test_project_metadata.py b/tests/unit/lib/telemetry/test_project_metadata.py index acafd73562..8bd6f485c3 100644 --- a/tests/unit/lib/telemetry/test_project_metadata.py +++ b/tests/unit/lib/telemetry/test_project_metadata.py @@ -77,24 +77,24 @@ def test_retrieve_project_name_from_git(self, origin, expected, sp_mock): @parameterized.expand( [ - ("C:/Users/aws/path/to/library/aws-sam-cli", "aws-sam-cli"), - ("C:\\Users\\aws\\Windows\\path\\aws-sam-cli", "aws-sam-cli"), - ("C:/", ""), - ("C:\\", ""), - ("E:/path/to/another/dir", "dir"), - ("This/one/doesn't/start/with/a/letter", "letter"), - ("/banana", "banana"), - ("D:/one/more/just/to/be/safe", "safe"), + ("C:/Users/aws/path/to/library/aws-sam-cli"), + ("C:\\Users\\aws\\Windows\\path\\aws-sam-cli"), + ("C:/"), + ("C:\\"), + ("E:/path/to/another/dir"), + ("This/one/doesn't/start/with/a/letter"), + ("/banana"), + ("D:/one/more/just/to/be/safe"), ] ) @patch("samcli.lib.telemetry.project_metadata.getcwd") @patch("samcli.lib.telemetry.project_metadata.subprocess.run") - def test_retrieve_project_name_from_dir(self, cwd, expected, sp_mock, cwd_mock): + def test_retrieve_project_name_from_dir(self, cwd, sp_mock, cwd_mock): sp_mock.side_effect = CalledProcessError(128, ["git", "config", "--get", "remote.origin.url"]) cwd_mock.return_value = cwd project_name = get_project_name() - self.assertEqual(project_name, str(uuid5(NAMESPACE_URL, expected))) + self.assertEqual(project_name, str(uuid5(NAMESPACE_URL, cwd.replace("\\", "/")))) @parameterized.expand( [ From e23b69ab46fc2871239dcde327f31cf7b886634d Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Mon, 13 Jun 2022 16:36:08 -0700 Subject: [PATCH 03/23] Implement event data structure and relevant unit tests (#3955) * Implement event data structure and relevant unit tests * Implement requested changes * Remove unused (useless) file * Remove unnecessary ABC class --- samcli/lib/telemetry/event.py | 72 ++++++++++++++++++++++++++ tests/unit/lib/telemetry/test_event.py | 50 ++++++++++++++++++ 2 files changed, 122 insertions(+) create mode 100644 samcli/lib/telemetry/event.py create mode 100644 tests/unit/lib/telemetry/test_event.py diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py new file mode 100644 index 0000000000..450eef6666 --- /dev/null +++ b/samcli/lib/telemetry/event.py @@ -0,0 +1,72 @@ +""" +Represents Events and their values. +""" + +from enum import Enum +from typing import List + + +class EventName(Enum): + """Enum for the names of available events to track.""" + + USED_FEATURE = "UsedFeature" + DEPLOY = "Deploy" + BUILD_RUNTIME = "BuildRuntime" + + +class EventType: + """Class for Events and the types of values they may have.""" + + _events = { + EventName.USED_FEATURE: [ + "ESBuild", + "Accelerate", + "LocalTest", + "CDK", + ], + EventName.DEPLOY: [ + "CreateChangeSetStart", + "CreateChangeSetInProgress", + "CreateChangeSetFailed", + "CreateChangeSetSuccess", + ], + } + + @staticmethod + def get_accepted_values(event_name: EventName) -> List[str]: + """Get all acceptable values for a given Event.""" + if event_name not in EventType._events: + return [] + return EventType._events[event_name] + + +class Event: + """Class to represent Events that occur in SAM CLI.""" + + event_name: EventName + event_value: str # Validated by EventType.get_accepted_values to never be an arbitrary string + + def __init__(self, event_name: str, event_value: str): + Event._verify_event(event_name, event_value) + self.event_name = EventName(event_name) + self.event_value = event_value + + def __eq__(self, other): + return self.event_name == other.event_name and self.event_value == other.event_value + + @staticmethod + def _verify_event(event_name: str, event_value: str) -> None: + """Raise an EventCreationError if either the event name or value is not valid.""" + if event_name not in Event._get_event_names(): + raise EventCreationError(f"Event '{event_name}' does not exist.") + if event_value not in EventType.get_accepted_values(EventName(event_name)): + raise EventCreationError(f"Event '{event_name}' does not accept value '{event_value}'.") + + @staticmethod + def _get_event_names() -> List[str]: + """Retrieves a list of all valid event names.""" + return [event.value for event in EventName] + + +class EventCreationError(Exception): + """Exception called when an Event is not properly created.""" diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py new file mode 100644 index 0000000000..74ca23d7dc --- /dev/null +++ b/tests/unit/lib/telemetry/test_event.py @@ -0,0 +1,50 @@ +""" +Module for testing the event.py methods and classes. +""" + +from enum import Enum +from unittest import TestCase +from unittest.mock import Mock, patch + +from samcli.lib.telemetry.event import Event, EventCreationError + + +class DummyEventName(Enum): + TEST_ONE = "TestOne" + TEST_TWO = "TestTwo" + TEST_THREE = "TestThree" + + +class TestEventCreation(TestCase): + @patch("samcli.lib.telemetry.event.Event._verify_event") + @patch("samcli.lib.telemetry.event.EventType") + @patch("samcli.lib.telemetry.event.EventName") + def test_create_event_exists(self, name_mock, type_mock, verify_mock): + name_mock.return_value = Mock(value="TestOne") + type_mock.get_accepted_values.return_value = ["value1", "value2"] + verify_mock.return_value = None + + test_event = Event("TestOne", "value1") + + name_mock.assert_called_once() + self.assertEqual(test_event.event_name.value, "TestOne") + self.assertEqual(test_event.event_value, "value1") + + @patch("samcli.lib.telemetry.event.EventType") + @patch("samcli.lib.telemetry.event.EventName") + @patch("samcli.lib.telemetry.event.Event._get_event_names") + def test_create_event_value_doesnt_exist(self, name_getter_mock, name_mock, type_mock): + name_getter_mock.return_value = ["TestOne"] + name_mock.return_value = Mock(value="TestOne") + type_mock.get_accepted_values.return_value = ["value1", "value2"] + + with self.assertRaises(EventCreationError) as e: + Event("TestOne", "value3") + + self.assertEqual(e.exception.args[0], "Event 'TestOne' does not accept value 'value3'.") + + def test_create_event_name_doesnt_exist(self): + with self.assertRaises(EventCreationError) as e: + Event("SomeEventThatDoesn'tExist", "value1") + + self.assertEqual(e.exception.args[0], "Event 'SomeEventThatDoesn'tExist' does not exist.") From 43a979342d8863922e5486ae3033888cd97cf732 Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Wed, 15 Jun 2022 15:00:13 -0700 Subject: [PATCH 04/23] Implement tracker methods (#3970) * Implement tracker methods * Improve readability of Event's __repr__ method * Add method to convert Event to dictionary for JSON-compatibility --- samcli/lib/telemetry/event.py | 53 +++++++++++++++++++++++++- tests/unit/lib/telemetry/test_event.py | 32 +++++++++++++++- 2 files changed, 83 insertions(+), 2 deletions(-) diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index 450eef6666..60635172a3 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -34,7 +34,7 @@ class EventType: @staticmethod def get_accepted_values(event_name: EventName) -> List[str]: - """Get all acceptable values for a given Event.""" + """Get all acceptable values for a given Event name.""" if event_name not in EventType._events: return [] return EventType._events[event_name] @@ -54,6 +54,12 @@ def __init__(self, event_name: str, event_value: str): def __eq__(self, other): return self.event_name == other.event_name and self.event_value == other.event_value + def __repr__(self): + return f"Event(event_name={self.event_name.value}, event_value={self.event_value})" + + def to_json(self): + return {"event_name": self.event_name.value, "event_value": self.event_value} + @staticmethod def _verify_event(event_name: str, event_value: str) -> None: """Raise an EventCreationError if either the event name or value is not valid.""" @@ -68,5 +74,50 @@ def _get_event_names() -> List[str]: return [event.value for event in EventName] +class EventTracker: + """Class to track and recreate Events as they occur.""" + + _events: List[Event] = [] + + @staticmethod + def track_event(event_name: str, event_value: str): + """Method to track an event where and when it occurs. + + Place this method in the codepath of the event that you would + like to track. For instance, if you would like to track when + FeatureX is used, append this method to the end of that function. + + Parameters + ---------- + event_name: str + The name of the Event. Must be a valid EventName value, or an + EventCreationError will be thrown. + event_value: str + The value of the Event. Must be a valid EventType value for the + passed event_name, or an EventCreationError will be thrown. + + Examples + -------- + >>> def feature_x(...): + # do things + EventTracker.track_event("UsedFeature", "FeatureX") + + >>> def feature_y(...) -> Any: + # do things + EventTracker.track_event("UsedFeature", "FeatureY") + return some_value + """ + EventTracker._events.append(Event(event_name, event_value)) + + @staticmethod + def get_tracked_events() -> List[Event]: + return EventTracker._events + + @staticmethod + def clear_trackers(): + """Clear the current list of tracked Events before the next session.""" + EventTracker._events = [] + + class EventCreationError(Exception): """Exception called when an Event is not properly created.""" diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py index 74ca23d7dc..b9d6f58c2f 100644 --- a/tests/unit/lib/telemetry/test_event.py +++ b/tests/unit/lib/telemetry/test_event.py @@ -6,7 +6,7 @@ from unittest import TestCase from unittest.mock import Mock, patch -from samcli.lib.telemetry.event import Event, EventCreationError +from samcli.lib.telemetry.event import Event, EventCreationError, EventTracker class DummyEventName(Enum): @@ -48,3 +48,33 @@ def test_create_event_name_doesnt_exist(self): Event("SomeEventThatDoesn'tExist", "value1") self.assertEqual(e.exception.args[0], "Event 'SomeEventThatDoesn'tExist' does not exist.") + + @patch("samcli.lib.telemetry.event.Event._verify_event") + @patch("samcli.lib.telemetry.event.EventType") + @patch("samcli.lib.telemetry.event.EventName") + def test_event_to_json(self, name_mock, type_mock, verify_mock): + name_mock.return_value = Mock(value="Testing") + type_mock.get_accepted_values.return_value = ["value1"] + verify_mock.return_value = None + + test_event = Event("Testing", "value1") + + self.assertEqual(test_event.to_json(), {"event_name": "Testing", "event_value": "value1"}) + + +class TestEventTracker(TestCase): + @patch("samcli.lib.telemetry.event.Event") + def test_track_event(self, event_mock): + # Test that an event can be tracked + dummy_event = Mock(event_name="Test", event_value="SomeValue") + event_mock.return_value = dummy_event + + EventTracker.track_event("Test", "SomeValue") + + self.assertEqual(len(EventTracker._events), 1) + self.assertEqual(EventTracker._events[0], dummy_event) + + # Test that the Event list will be cleared + EventTracker.clear_trackers() + + self.assertEqual(len(EventTracker._events), 0) From ae7de58a58573a6d72b7ce79f1ba61f3fa4b50c8 Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Wed, 22 Jun 2022 11:31:33 -0700 Subject: [PATCH 05/23] Send Event metrics via Telemetry (#3979) * Send Event metrics via Telemetry * Add unit tests for event telemetry * Simplify event telemetry unit tests * Clean up unit tests --- samcli/lib/telemetry/metric.py | 4 ++ .../telemetry/test_experimental_metric.py | 3 ++ tests/unit/lib/telemetry/test_metric.py | 44 +++++++++++++++++++ 3 files changed, 51 insertions(+) diff --git a/samcli/lib/telemetry/metric.py b/samcli/lib/telemetry/metric.py index 8fc803fba1..006bb75323 100644 --- a/samcli/lib/telemetry/metric.py +++ b/samcli/lib/telemetry/metric.py @@ -17,6 +17,7 @@ from samcli.lib.warnings.sam_cli_warning import TemplateWarningsChecker from samcli.commands.exceptions import UserException from samcli.lib.telemetry.cicd import CICDDetector, CICDPlatform +from samcli.lib.telemetry.event import EventTracker from samcli.lib.telemetry.project_metadata import get_git_remote_origin_url, get_project_name, get_initial_commit_hash from samcli.commands._utils.experimental import get_all_experimental_statues from .telemetry import Telemetry @@ -158,6 +159,9 @@ def wrapped(*args, **kwargs): metric_specific_attributes["gitOrigin"] = get_git_remote_origin_url() metric_specific_attributes["projectName"] = get_project_name() metric_specific_attributes["initialCommit"] = get_initial_commit_hash() + # Event metrics + metric_specific_attributes["events"] = [e.to_json() for e in EventTracker.get_tracked_events()] + EventTracker.clear_trackers() metric.add_data("metricSpecificAttributes", metric_specific_attributes) # Metric about command's execution characteristics metric.add_data("duration", duration_fn()) diff --git a/tests/integration/telemetry/test_experimental_metric.py b/tests/integration/telemetry/test_experimental_metric.py index 2bcd93e340..98bd45649a 100644 --- a/tests/integration/telemetry/test_experimental_metric.py +++ b/tests/integration/telemetry/test_experimental_metric.py @@ -59,6 +59,7 @@ def test_must_send_experimental_metrics_if_experimental_command(self): "gitOrigin": ANY, "projectName": ANY, "initialCommit": ANY, + "events": ANY, }, "duration": ANY, "exitReason": ANY, @@ -113,6 +114,7 @@ def test_must_send_experimental_metrics_if_experimental_option(self): "gitOrigin": ANY, "projectName": ANY, "initialCommit": ANY, + "events": ANY, }, "duration": ANY, "exitReason": ANY, @@ -175,6 +177,7 @@ def test_must_send_cdk_project_type_metrics(self): "gitOrigin": ANY, "projectName": ANY, "initialCommit": ANY, + "events": ANY, }, "duration": ANY, "exitReason": ANY, diff --git a/tests/unit/lib/telemetry/test_metric.py b/tests/unit/lib/telemetry/test_metric.py index e4b59fd6ec..7d14233059 100644 --- a/tests/unit/lib/telemetry/test_metric.py +++ b/tests/unit/lib/telemetry/test_metric.py @@ -9,6 +9,7 @@ from unittest import TestCase from unittest.mock import patch, Mock, ANY, call +from samcli.lib.telemetry.event import Event, EventTracker import samcli.lib.telemetry.metric from samcli.lib.telemetry.cicd import CICDPlatform @@ -339,6 +340,49 @@ def real_fn(a, b=None): "The command metrics be emitted when used as a decorator", ) + @parameterized.expand( + [ + ([],), + ([Mock(event_name=Mock(value="TestEvent"), event_value="TestValue")],), + ( + [ + Mock(event_name=Mock(value="Test1"), event_value="TestValue1"), + Mock(event_name=Mock(value="Test2"), event_value="TestValue2"), + ], + ), + ( + [ + Mock(event_name=Mock(value="T1"), event_value="1"), + Mock(event_name=Mock(value="T2"), event_value="2"), + Mock(event_name=Mock(value="T3"), event_value="3"), + ], + ), + ] + ) + @patch("samcli.lib.telemetry.metric.Context") + @patch("samcli.lib.telemetry.event.EventTracker.clear_trackers", side_effect=EventTracker.clear_trackers) + def test_must_return_list_of_events(self, events, clr_mock, ContextMock): + ContextMock.get_current_context.return_value = self.context_mock + clr_mock.clear_trackers.return_value = EventTracker.clear_trackers() + for e in events: + e.to_json.return_value = Event.to_json(e) + + def func_with_event(): + for e in events: + EventTracker._events.append(e) + + expected = [e.to_json() for e in events] + + track_command(func_with_event)() + + args, _ = self.telemetry_instance.emit.call_args_list[0] + metric = args[0] + assert metric.get_metric_name() == "commandRun" + metric_events = metric.get_data()["metricSpecificAttributes"]["events"] + clr_mock.assert_called() + self.assertEqual(len(events), len(metric_events)) + self.assertEqual(metric_events, expected) + class TestParameterCapture(TestCase): def setUp(self): From 5b131ee0f2d71d07d7d64d5445cf98ee4b48e2c0 Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Fri, 24 Jun 2022 11:53:39 -0700 Subject: [PATCH 06/23] Add BuildRuntime event and trackers (#3994) * Add BuildRuntime Events * Remove unnecessary file * Prevent tracked Event 'spillage' from previous tests * Fix builder logic * Redefine BuildRuntime to focus on function runtimes * Remove unnecessary file (again) --- samcli/commands/build/build_context.py | 4 +++ samcli/lib/telemetry/event.py | 5 +++- .../commands/buildcmd/test_build_context.py | 4 +-- .../unit/lib/build_module/test_app_builder.py | 25 ++++++++++++++++--- 4 files changed, 32 insertions(+), 6 deletions(-) diff --git a/samcli/commands/build/build_context.py b/samcli/commands/build/build_context.py index 817547402c..59f9e4b25c 100644 --- a/samcli/commands/build/build_context.py +++ b/samcli/commands/build/build_context.py @@ -11,6 +11,7 @@ from samcli.commands._utils.experimental import ExperimentalFlag, prompt_experimental from samcli.lib.providers.sam_api_provider import SamApiProvider +from samcli.lib.telemetry.event import EventTracker from samcli.lib.utils.packagetype import IMAGE from samcli.commands._utils.template import get_template_data @@ -267,6 +268,9 @@ def run(self): modified_template = nested_stack_manager.generate_auto_dependency_layer_stack() move_template(stack.location, output_template_path, modified_template) + for f in self.get_resources_to_build().functions: + EventTracker.track_event("BuildFunctionRuntime", f.runtime) + click.secho("\nBuild Succeeded", fg="green") # try to use relpath so the command is easier to understand, however, diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index 60635172a3..c9e8b92d3e 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -5,13 +5,15 @@ from enum import Enum from typing import List +from samcli.local.common.runtime_template import INIT_RUNTIMES + class EventName(Enum): """Enum for the names of available events to track.""" USED_FEATURE = "UsedFeature" DEPLOY = "Deploy" - BUILD_RUNTIME = "BuildRuntime" + BUILD_FUNCTION_RUNTIME = "BuildFunctionRuntime" class EventType: @@ -30,6 +32,7 @@ class EventType: "CreateChangeSetFailed", "CreateChangeSetSuccess", ], + EventName.BUILD_FUNCTION_RUNTIME: INIT_RUNTIMES, } @staticmethod diff --git a/tests/unit/commands/buildcmd/test_build_context.py b/tests/unit/commands/buildcmd/test_build_context.py index ef9f2ce913..5460d59812 100644 --- a/tests/unit/commands/buildcmd/test_build_context.py +++ b/tests/unit/commands/buildcmd/test_build_context.py @@ -1,6 +1,6 @@ import os from unittest import TestCase -from unittest.mock import patch, Mock, ANY, call +from unittest.mock import MagicMock, patch, Mock, ANY, call from parameterized import parameterized @@ -661,7 +661,7 @@ def test_run_sync_build_context( root_stack.stack_path: "./build_dir/template.yaml", child_stack.stack_path: "./build_dir/abcd/template.yaml", } - resources_mock.return_value = Mock() + resources_mock.return_value = MagicMock() builder_mock = ApplicationBuilderMock.return_value = Mock() artifacts = "artifacts" diff --git a/tests/unit/lib/build_module/test_app_builder.py b/tests/unit/lib/build_module/test_app_builder.py index 8889741251..e9b348db09 100644 --- a/tests/unit/lib/build_module/test_app_builder.py +++ b/tests/unit/lib/build_module/test_app_builder.py @@ -25,6 +25,7 @@ DockerConnectionError, ) from samcli.commands.local.cli_common.user_exceptions import InvalidFunctionPropertyType +from samcli.lib.telemetry.event import EventName, EventTracker from samcli.lib.utils.architecture import X86_64, ARM64 from samcli.lib.utils.packagetype import IMAGE, ZIP from samcli.lib.utils.stream_writer import StreamWriter @@ -1476,13 +1477,20 @@ def setUp(self): Mock(), "/build/dir", "/base/dir", "/cache/dir", mode="mode", stream_writer=StreamWriter(sys.stderr) ) + def tearDown(self): + EventTracker.clear_trackers() + @parameterized.expand([([],), (["ExpFlag1", "ExpFlag2"],)]) + @patch("samcli.lib.telemetry.event.EventType.get_accepted_values") @patch("samcli.lib.build.app_builder.LambdaBuilder") @patch("samcli.lib.build.app_builder.get_enabled_experimental_flags") - def test_must_use_lambda_builder(self, experimental_flags, experimental_flags_mock, lambda_builder_mock): + def test_must_use_lambda_builder( + self, experimental_flags, experimental_flags_mock, lambda_builder_mock, event_mock + ): experimental_flags_mock.return_value = experimental_flags config_mock = Mock() builder_instance_mock = lambda_builder_mock.return_value = Mock() + event_mock.return_value = ["runtime"] result = self.builder._build_function_in_process( config_mock, @@ -1545,10 +1553,14 @@ def test_must_raise_on_error(self, lambda_builder_mock): True, ) + @patch("samcli.lib.telemetry.event.EventType.get_accepted_values") @patch("samcli.lib.build.app_builder.LambdaBuilder") @patch("samcli.lib.build.app_builder.get_enabled_experimental_flags") - def test_building_with_experimental_flags(self, get_enabled_experimental_flags_mock, lambda_builder_mock): + def test_building_with_experimental_flags( + self, get_enabled_experimental_flags_mock, lambda_builder_mock, event_mock + ): get_enabled_experimental_flags_mock.return_value = ["A", "B", "C"] + event_mock.return_value = ["runtime"] config_mock = Mock() self.builder._build_function_in_process( config_mock, @@ -1600,11 +1612,18 @@ def setUp(self): ) self.builder._parse_builder_response = Mock() + def tearDown(self): + EventTracker.clear_trackers() + + @patch("samcli.lib.telemetry.event.EventType.get_accepted_values") @patch("samcli.lib.build.app_builder.LambdaBuildContainer") @patch("samcli.lib.build.app_builder.lambda_builders_protocol_version") @patch("samcli.lib.build.app_builder.LOG") @patch("samcli.lib.build.app_builder.osutils") - def test_must_build_in_container(self, osutils_mock, LOGMock, protocol_version_mock, LambdaBuildContainerMock): + def test_must_build_in_container( + self, osutils_mock, LOGMock, protocol_version_mock, LambdaBuildContainerMock, event_mock + ): + event_mock.return_value = "runtime" config = Mock() log_level = LOGMock.getEffectiveLevel.return_value = "foo" stdout_data = "container stdout response data" From e62a6559aeaa0156fced271522299d0bd5b3c246 Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Tue, 28 Jun 2022 16:05:45 -0700 Subject: [PATCH 07/23] Add UsedFeature event and trackers (#4003) * Add UsedFeature command and trackers * Remove LocalTest events Events regarding sam local will be implemented at a later time. * Prevent methods from failing if track_event fails * Reformat code to match current standard * Use correct string formatting * Use proper LOG message --- samcli/commands/build/build_context.py | 2 ++ samcli/commands/sync/command.py | 2 ++ samcli/lib/telemetry/event.py | 10 ++++++++-- samcli/lib/telemetry/metric.py | 2 ++ 4 files changed, 14 insertions(+), 2 deletions(-) diff --git a/samcli/commands/build/build_context.py b/samcli/commands/build/build_context.py index 59f9e4b25c..0f675a442a 100644 --- a/samcli/commands/build/build_context.py +++ b/samcli/commands/build/build_context.py @@ -270,6 +270,8 @@ def run(self): for f in self.get_resources_to_build().functions: EventTracker.track_event("BuildFunctionRuntime", f.runtime) + if f.metadata and f.metadata.get("BuildMethod", "") == "esbuild": + EventTracker.track_event("UsedFeature", "ESBuild") click.secho("\nBuild Succeeded", fg="green") diff --git a/samcli/commands/sync/command.py b/samcli/commands/sync/command.py index ee91b0570a..8586a3bdbf 100644 --- a/samcli/commands/sync/command.py +++ b/samcli/commands/sync/command.py @@ -27,6 +27,7 @@ ) from samcli.cli.cli_config_file import configuration_option, TomlProvider from samcli.commands._utils.click_mutex import ClickMutex +from samcli.lib.telemetry.event import EventTracker from samcli.lib.utils.colors import Colored from samcli.lib.utils.version_checker import check_newer_version from samcli.lib.bootstrap.bootstrap import manage_stack @@ -260,6 +261,7 @@ def do_cli( set_experimental(ExperimentalFlag.Accelerate) update_experimental_context() + EventTracker.track_event("UsedFeature", "Accelerate") with BuildContext( resource_identifier=None, diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index c9e8b92d3e..75529474b7 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -3,11 +3,15 @@ """ from enum import Enum +import logging from typing import List from samcli.local.common.runtime_template import INIT_RUNTIMES +LOG = logging.getLogger(__name__) + + class EventName(Enum): """Enum for the names of available events to track.""" @@ -23,7 +27,6 @@ class EventType: EventName.USED_FEATURE: [ "ESBuild", "Accelerate", - "LocalTest", "CDK", ], EventName.DEPLOY: [ @@ -110,7 +113,10 @@ def track_event(event_name: str, event_value: str): EventTracker.track_event("UsedFeature", "FeatureY") return some_value """ - EventTracker._events.append(Event(event_name, event_value)) + try: + EventTracker._events.append(Event(event_name, event_value)) + except EventCreationError as e: + LOG.debug("Error occurred while trying to track an event: %s", e) @staticmethod def get_tracked_events() -> List[Event]: diff --git a/samcli/lib/telemetry/metric.py b/samcli/lib/telemetry/metric.py index 006bb75323..4de95656c5 100644 --- a/samcli/lib/telemetry/metric.py +++ b/samcli/lib/telemetry/metric.py @@ -146,6 +146,8 @@ def wrapped(*args, **kwargs): try: template_dict = ctx.template_dict project_type = ProjectTypes.CDK.value if is_cdk_project(template_dict) else ProjectTypes.CFN.value + if project_type == ProjectTypes.CDK.value: + EventTracker.track_event("UsedFeature", "CDK") metric_specific_attributes["projectType"] = project_type except AttributeError: LOG.debug("Template is not provided in context, skip adding project type metric") From c2790c9aabcaee0bed201cbaf8c6ec32537a48bb Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Thu, 30 Jun 2022 11:05:22 -0700 Subject: [PATCH 08/23] Add thread lock to EventTracker (#4019) * Add thread lock to EventTracker * Place lock in appropriate methods --- samcli/lib/telemetry/event.py | 11 ++++++++--- 1 file changed, 8 insertions(+), 3 deletions(-) diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index 75529474b7..30ea33715b 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -4,6 +4,7 @@ from enum import Enum import logging +import threading from typing import List from samcli.local.common.runtime_template import INIT_RUNTIMES @@ -84,6 +85,7 @@ class EventTracker: """Class to track and recreate Events as they occur.""" _events: List[Event] = [] + _event_lock = threading.Lock() @staticmethod def track_event(event_name: str, event_value: str): @@ -114,18 +116,21 @@ def track_event(event_name: str, event_value: str): return some_value """ try: - EventTracker._events.append(Event(event_name, event_value)) + with EventTracker._event_lock: + EventTracker._events.append(Event(event_name, event_value)) except EventCreationError as e: LOG.debug("Error occurred while trying to track an event: %s", e) @staticmethod def get_tracked_events() -> List[Event]: - return EventTracker._events + with EventTracker._event_lock: + return EventTracker._events @staticmethod def clear_trackers(): """Clear the current list of tracked Events before the next session.""" - EventTracker._events = [] + with EventTracker._event_lock: + EventTracker._events = [] class EventCreationError(Exception): From 6edf835978322759e0ee200928c1afeeafd5e50c Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Tue, 5 Jul 2022 20:47:43 -0700 Subject: [PATCH 09/23] Refactor Event data structure (#4027) * Add new attributes to Event datastructure * Fix non-JSON-serializable field in Event * Fix repr to ensure SQL casting will work * Add comment for timestamp method clarity --- samcli/lib/telemetry/event.py | 17 +++++++++++++++-- tests/unit/lib/telemetry/test_event.py | 11 ++++++++--- 2 files changed, 23 insertions(+), 5 deletions(-) diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index 30ea33715b..e29794317f 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -2,6 +2,7 @@ Represents Events and their values. """ +from datetime import datetime from enum import Enum import logging import threading @@ -52,6 +53,8 @@ class Event: event_name: EventName event_value: str # Validated by EventType.get_accepted_values to never be an arbitrary string + thread_id = threading.get_ident() # The thread ID; used to group Events from the same command run + timestamp = datetime.utcnow() def __init__(self, event_name: str, event_value: str): Event._verify_event(event_name, event_value) @@ -62,10 +65,20 @@ def __eq__(self, other): return self.event_name == other.event_name and self.event_value == other.event_value def __repr__(self): - return f"Event(event_name={self.event_name.value}, event_value={self.event_value})" + return ( + f"Event(event_name={self.event_name.value}, " + f"event_value={self.event_value}, " + f"thread_id={self.thread_id}, " + f"timestamp={self.timestamp})" + ) def to_json(self): - return {"event_name": self.event_name.value, "event_value": self.event_value} + return { + "event_name": self.event_name.value, + "event_value": self.event_value, + "thread_id": self.thread_id, + "timestamp": str(self.timestamp)[:-3], # cut time's microseconds from 6 -> 3 figures to allow SQL casting + } @staticmethod def _verify_event(event_name: str, event_value: str) -> None: diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py index b9d6f58c2f..eb6fba8ca2 100644 --- a/tests/unit/lib/telemetry/test_event.py +++ b/tests/unit/lib/telemetry/test_event.py @@ -3,8 +3,9 @@ """ from enum import Enum +import threading from unittest import TestCase -from unittest.mock import Mock, patch +from unittest.mock import ANY, Mock, patch from samcli.lib.telemetry.event import Event, EventCreationError, EventTracker @@ -29,6 +30,7 @@ def test_create_event_exists(self, name_mock, type_mock, verify_mock): name_mock.assert_called_once() self.assertEqual(test_event.event_name.value, "TestOne") self.assertEqual(test_event.event_value, "value1") + self.assertEqual(test_event.thread_id, threading.get_ident()) # Should be on the same thread @patch("samcli.lib.telemetry.event.EventType") @patch("samcli.lib.telemetry.event.EventName") @@ -59,14 +61,17 @@ def test_event_to_json(self, name_mock, type_mock, verify_mock): test_event = Event("Testing", "value1") - self.assertEqual(test_event.to_json(), {"event_name": "Testing", "event_value": "value1"}) + self.assertEqual( + test_event.to_json(), + {"event_name": "Testing", "event_value": "value1", "thread_id": threading.get_ident(), "timestamp": ANY}, + ) class TestEventTracker(TestCase): @patch("samcli.lib.telemetry.event.Event") def test_track_event(self, event_mock): # Test that an event can be tracked - dummy_event = Mock(event_name="Test", event_value="SomeValue") + dummy_event = Mock(event_name="Test", event_value="SomeValue", thread_id=threading.get_ident(), timestamp=ANY) event_mock.return_value = dummy_event EventTracker.track_event("Test", "SomeValue") From 4cbca016a3ba4b554b933283eb71c338a53a960b Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Wed, 6 Jul 2022 15:00:09 -0700 Subject: [PATCH 10/23] Update tests to verify EventTracker thread lock is working (#4035) --- tests/unit/lib/telemetry/test_event.py | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py index eb6fba8ca2..c8ca9705dc 100644 --- a/tests/unit/lib/telemetry/test_event.py +++ b/tests/unit/lib/telemetry/test_event.py @@ -68,8 +68,12 @@ def test_event_to_json(self, name_mock, type_mock, verify_mock): class TestEventTracker(TestCase): + @patch("samcli.lib.telemetry.event.EventTracker._event_lock") @patch("samcli.lib.telemetry.event.Event") - def test_track_event(self, event_mock): + def test_track_event(self, event_mock, lock_mock): + lock_mock.__enter__ = Mock() + lock_mock.__exit__ = Mock() + # Test that an event can be tracked dummy_event = Mock(event_name="Test", event_value="SomeValue", thread_id=threading.get_ident(), timestamp=ANY) event_mock.return_value = dummy_event @@ -78,8 +82,14 @@ def test_track_event(self, event_mock): self.assertEqual(len(EventTracker._events), 1) self.assertEqual(EventTracker._events[0], dummy_event) + lock_mock.__enter__.assert_called() # Lock should have been accessed + lock_mock.__exit__.assert_called() + lock_mock.__enter__.reset_mock() + lock_mock.__exit__.reset_mock() # Test that the Event list will be cleared EventTracker.clear_trackers() self.assertEqual(len(EventTracker._events), 0) + lock_mock.__enter__.assert_called() # Lock should have been accessed + lock_mock.__exit__.assert_called() From 33ca6c5a4bb0596ef7b0d650a4e2c3fb93da2781 Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Thu, 14 Jul 2022 23:21:22 -0700 Subject: [PATCH 11/23] Add send_events method to EventTracker (#4039) * Add framework for Event-sending method * Perform some general refactors and cleanup * Implement EventTracker Telemetry unit tests * Cleanup tests and unused imports * Update Metric name for consistency * Repair failing unit test * (Hopefully) repair broken integration test * *Actually* repair broken integration test I had the >= logic backwards lol * Fix integration test For sure this time * Really fix the integration test Windows development is not fun * Properly fix integration test * Reformat files * Implement requested changes * Add Lock logic to send_events method * Implement requested changes * Repair failing tests --- samcli/lib/telemetry/event.py | 33 +++++++- samcli/lib/telemetry/metric.py | 4 +- .../telemetry/test_experimental_metric.py | 7 +- tests/unit/lib/telemetry/test_event.py | 79 ++++++++++++++++++- tests/unit/lib/telemetry/test_metric.py | 46 ++--------- 5 files changed, 119 insertions(+), 50 deletions(-) diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index e29794317f..fe13481d77 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -8,6 +8,7 @@ import threading from typing import List +from samcli.lib.telemetry.telemetry import Telemetry from samcli.local.common.runtime_template import INIT_RUNTIMES @@ -54,12 +55,13 @@ class Event: event_name: EventName event_value: str # Validated by EventType.get_accepted_values to never be an arbitrary string thread_id = threading.get_ident() # The thread ID; used to group Events from the same command run - timestamp = datetime.utcnow() + time_stamp: str def __init__(self, event_name: str, event_value: str): Event._verify_event(event_name, event_value) self.event_name = EventName(event_name) self.event_value = event_value + self.time_stamp = str(datetime.utcnow())[:-3] # format microseconds from 6 -> 3 figures to allow SQL casting def __eq__(self, other): return self.event_name == other.event_name and self.event_value == other.event_value @@ -69,7 +71,7 @@ def __repr__(self): f"Event(event_name={self.event_name.value}, " f"event_value={self.event_value}, " f"thread_id={self.thread_id}, " - f"timestamp={self.timestamp})" + f"time_stamp={self.time_stamp})" ) def to_json(self): @@ -77,7 +79,7 @@ def to_json(self): "event_name": self.event_name.value, "event_value": self.event_value, "thread_id": self.thread_id, - "timestamp": str(self.timestamp)[:-3], # cut time's microseconds from 6 -> 3 figures to allow SQL casting + "time_stamp": self.time_stamp, } @staticmethod @@ -100,6 +102,8 @@ class EventTracker: _events: List[Event] = [] _event_lock = threading.Lock() + MAX_EVENTS: int = 50 # Maximum number of events to store before sending + @staticmethod def track_event(event_name: str, event_value: str): """Method to track an event where and when it occurs. @@ -129,8 +133,13 @@ def track_event(event_name: str, event_value: str): return some_value """ try: + should_send: bool = False with EventTracker._event_lock: EventTracker._events.append(Event(event_name, event_value)) + if len(EventTracker._events) >= EventTracker.MAX_EVENTS: + should_send = True + if should_send: + EventTracker.send_events() except EventCreationError as e: LOG.debug("Error occurred while trying to track an event: %s", e) @@ -145,6 +154,24 @@ def clear_trackers(): with EventTracker._event_lock: EventTracker._events = [] + @staticmethod + def send_events(): + """Sends the current list of events via Telemetry.""" + from samcli.lib.telemetry.metric import Metric # pylint: disable=cyclic-import + + with EventTracker._event_lock: + if not EventTracker._events: # Don't do anything if there are no events to send + return + + telemetry = Telemetry() + + metric = Metric("events") + msa = {} + msa["events"] = [e.to_json() for e in EventTracker._events] + metric.add_data("metricSpecificAttributes", msa) + telemetry.emit(metric) + EventTracker._events = [] # Manual clear_trackers() since we're within the lock + class EventCreationError(Exception): """Exception called when an Event is not properly created.""" diff --git a/samcli/lib/telemetry/metric.py b/samcli/lib/telemetry/metric.py index 4de95656c5..028eafd8df 100644 --- a/samcli/lib/telemetry/metric.py +++ b/samcli/lib/telemetry/metric.py @@ -161,14 +161,12 @@ def wrapped(*args, **kwargs): metric_specific_attributes["gitOrigin"] = get_git_remote_origin_url() metric_specific_attributes["projectName"] = get_project_name() metric_specific_attributes["initialCommit"] = get_initial_commit_hash() - # Event metrics - metric_specific_attributes["events"] = [e.to_json() for e in EventTracker.get_tracked_events()] - EventTracker.clear_trackers() metric.add_data("metricSpecificAttributes", metric_specific_attributes) # Metric about command's execution characteristics metric.add_data("duration", duration_fn()) metric.add_data("exitReason", exit_reason) metric.add_data("exitCode", exit_code) + EventTracker.send_events() # Sends Event metrics to Telemetry before commandRun metrics telemetry.emit(metric) except RuntimeError: LOG.debug("Unable to find Click Context for getting session_id.") diff --git a/tests/integration/telemetry/test_experimental_metric.py b/tests/integration/telemetry/test_experimental_metric.py index 98bd45649a..05a73f6ab1 100644 --- a/tests/integration/telemetry/test_experimental_metric.py +++ b/tests/integration/telemetry/test_experimental_metric.py @@ -59,7 +59,6 @@ def test_must_send_experimental_metrics_if_experimental_command(self): "gitOrigin": ANY, "projectName": ANY, "initialCommit": ANY, - "events": ANY, }, "duration": ANY, "exitReason": ANY, @@ -114,7 +113,6 @@ def test_must_send_experimental_metrics_if_experimental_option(self): "gitOrigin": ANY, "projectName": ANY, "initialCommit": ANY, - "events": ANY, }, "duration": ANY, "exitReason": ANY, @@ -152,8 +150,8 @@ def test_must_send_cdk_project_type_metrics(self): process.communicate() all_requests = server.get_all_requests() - self.assertEqual(1, len(all_requests), "Command run metric must be sent") - request = all_requests[0] + self.assertGreaterEqual(len(all_requests), 1, "Command run metric must be sent") + request = all_requests[-1] # commandRun metric is last bc of ordering 'send_events' vs 'telemetry.emit' self.assertIn("Content-Type", request["headers"]) self.assertEqual(request["headers"]["Content-Type"], "application/json") @@ -177,7 +175,6 @@ def test_must_send_cdk_project_type_metrics(self): "gitOrigin": ANY, "projectName": ANY, "initialCommit": ANY, - "events": ANY, }, "duration": ANY, "exitReason": ANY, diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py index c8ca9705dc..9802b1b75a 100644 --- a/tests/unit/lib/telemetry/test_event.py +++ b/tests/unit/lib/telemetry/test_event.py @@ -63,7 +63,7 @@ def test_event_to_json(self, name_mock, type_mock, verify_mock): self.assertEqual( test_event.to_json(), - {"event_name": "Testing", "event_value": "value1", "thread_id": threading.get_ident(), "timestamp": ANY}, + {"event_name": "Testing", "event_value": "value1", "thread_id": threading.get_ident(), "time_stamp": ANY}, ) @@ -93,3 +93,80 @@ def test_track_event(self, event_mock, lock_mock): self.assertEqual(len(EventTracker._events), 0) lock_mock.__enter__.assert_called() # Lock should have been accessed lock_mock.__exit__.assert_called() + + @patch("samcli.lib.telemetry.event.Telemetry") + def test_events_get_sent(self, telemetry_mock): + # Create fake emit to capture tracked events + dummy_telemetry = Mock() + emitted_events = [] + mock_emit = lambda x: emitted_events.append(x) + dummy_telemetry.emit.return_value = None + dummy_telemetry.emit.side_effect = mock_emit + telemetry_mock.return_value = dummy_telemetry + + # Verify that no events are sent if tracker is empty + EventTracker.send_events() + + self.assertEqual(emitted_events, []) # No events should have been collected + dummy_telemetry.emit.assert_not_called() # Nothing should have been sent (empty list) + + # Verify that events get sent when they exist in tracker + dummy_event = Mock( + event_name=Mock(value="Test"), event_value="SomeValue", thread_id=threading.get_ident(), time_stamp=ANY + ) + dummy_event.to_json.return_value = Event.to_json(dummy_event) + EventTracker._events.append(dummy_event) + + EventTracker.send_events() + + dummy_telemetry.emit.assert_called() + self.assertEqual(len(emitted_events), 1) # The list of metrics (1) is copied into emitted_events + metric_data = emitted_events[0].get_data() + expected_data = { + "requestId": ANY, + "installationId": ANY, + "sessionId": ANY, + "executionEnvironment": ANY, + "ci": ANY, + "pyversion": ANY, + "samcliVersion": ANY, + "metricSpecificAttributes": { + "events": [ + { + "event_name": "Test", + "event_value": "SomeValue", + "thread_id": ANY, + "time_stamp": ANY, + } + ] + }, + } + self.assertEqual(len(metric_data["metricSpecificAttributes"]["events"]), 1) # There is one event captured + self.assertEqual(metric_data, expected_data) + self.assertEqual(len(EventTracker._events), 0) # Events should have been sent and cleared + + @patch( + "samcli.lib.telemetry.event.EventTracker.send_events", + return_value=None, + ) + @patch("samcli.lib.telemetry.event.Event") + def test_track_event_events_sent_when_capacity_reached(self, event_mock, send_mock): + # Create dummy Event creator to bypass verification + def make_mock_event(name, value): + dummy = Mock(event_name=Mock(value=name), event_value=value, thread_id=ANY, time_stamp=ANY) + dummy.to_json.return_value = Event.to_json(dummy) + return dummy + + event_mock.return_value = make_mock_event + + # Fill EventTracker with almost enough events to reach capacity + for i in range(EventTracker.MAX_EVENTS - 1): + EventTracker.track_event(f"Name{i}", f"Value{i}") + + send_mock.assert_not_called() + self.assertEqual(len(EventTracker._events), EventTracker.MAX_EVENTS - 1) + + # Add one more event to trigger sending all events + EventTracker.track_event("TheStrawThat", "BreaksTheCamel'sBack") + + send_mock.assert_called() diff --git a/tests/unit/lib/telemetry/test_metric.py b/tests/unit/lib/telemetry/test_metric.py index 7d14233059..7835b8b1a8 100644 --- a/tests/unit/lib/telemetry/test_metric.py +++ b/tests/unit/lib/telemetry/test_metric.py @@ -9,7 +9,7 @@ from unittest import TestCase from unittest.mock import patch, Mock, ANY, call -from samcli.lib.telemetry.event import Event, EventTracker +from samcli.lib.telemetry.event import EventTracker import samcli.lib.telemetry.metric from samcli.lib.telemetry.cicd import CICDPlatform @@ -133,6 +133,7 @@ def setUp(self): GlobalConfigClassMock = Mock() self.telemetry_instance = TelemetryClassMock.return_value = Mock() self.gc_instance_mock = GlobalConfigClassMock.return_value = Mock() + EventTracker.clear_trackers() self.telemetry_class_patcher = patch("samcli.lib.telemetry.metric.Telemetry", TelemetryClassMock) self.gc_patcher = patch("samcli.lib.telemetry.metric.GlobalConfig", GlobalConfigClassMock) @@ -340,48 +341,17 @@ def real_fn(a, b=None): "The command metrics be emitted when used as a decorator", ) - @parameterized.expand( - [ - ([],), - ([Mock(event_name=Mock(value="TestEvent"), event_value="TestValue")],), - ( - [ - Mock(event_name=Mock(value="Test1"), event_value="TestValue1"), - Mock(event_name=Mock(value="Test2"), event_value="TestValue2"), - ], - ), - ( - [ - Mock(event_name=Mock(value="T1"), event_value="1"), - Mock(event_name=Mock(value="T2"), event_value="2"), - Mock(event_name=Mock(value="T3"), event_value="3"), - ], - ), - ] - ) + @patch("samcli.lib.telemetry.event.EventTracker.send_events", return_value=None) @patch("samcli.lib.telemetry.metric.Context") - @patch("samcli.lib.telemetry.event.EventTracker.clear_trackers", side_effect=EventTracker.clear_trackers) - def test_must_return_list_of_events(self, events, clr_mock, ContextMock): + def test_must_send_events(self, ContextMock, send_mock): ContextMock.get_current_context.return_value = self.context_mock - clr_mock.clear_trackers.return_value = EventTracker.clear_trackers() - for e in events: - e.to_json.return_value = Event.to_json(e) - def func_with_event(): - for e in events: - EventTracker._events.append(e) - - expected = [e.to_json() for e in events] + def real_fn(): + pass - track_command(func_with_event)() + track_command(real_fn)() - args, _ = self.telemetry_instance.emit.call_args_list[0] - metric = args[0] - assert metric.get_metric_name() == "commandRun" - metric_events = metric.get_data()["metricSpecificAttributes"]["events"] - clr_mock.assert_called() - self.assertEqual(len(events), len(metric_events)) - self.assertEqual(metric_events, expected) + send_mock.assert_called() class TestParameterCapture(TestCase): From f88493fd75affd63c0746b1bc6d5605eb12e22a2 Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Mon, 18 Jul 2022 09:24:20 -0700 Subject: [PATCH 12/23] Upgrade encryption algorithm from SHA-1 to SHA-256 (#4061) * Upgrade encryption algorithm from SHA1 to SHA256 * Make return value of hash JSON-serializable --- samcli/lib/telemetry/project_metadata.py | 14 ++++++++------ .../lib/telemetry/test_project_metadata.py | 18 +++++++++++++----- 2 files changed, 21 insertions(+), 11 deletions(-) diff --git a/samcli/lib/telemetry/project_metadata.py b/samcli/lib/telemetry/project_metadata.py index ac5818e737..c825db9022 100644 --- a/samcli/lib/telemetry/project_metadata.py +++ b/samcli/lib/telemetry/project_metadata.py @@ -2,11 +2,11 @@ Creates and encrypts metadata regarding SAM CLI projects. """ +import hashlib from os import getcwd import re import subprocess from typing import List, Optional -from uuid import uuid5, NAMESPACE_URL from samcli.cli.global_config import GlobalConfig @@ -18,7 +18,7 @@ def get_git_remote_origin_url() -> Optional[str]: Returns ------- str | None - A UUID5 encrypted string of the git remote origin url, formatted such that the + A SHA256 hexdigest string of the git remote origin url, formatted such that the encrypted value follows the pattern //.git. If telemetry is opted out of by the user, or the `.git` folder is not found (the directory is not a git repository), returns None @@ -46,7 +46,7 @@ def get_project_name() -> Optional[str]: Returns ------- str | None - A UUID5 encrypted string of either the name of the project, or the name of the + A SHA256 hexdigest string of either the name of the project, or the name of the current working directory that the command is running in. If telemetry is opted out of by the user, returns None """ @@ -72,7 +72,7 @@ def get_initial_commit_hash() -> Optional[str]: Returns ------- str | None - A UUID5 encrypted string of the git project's initial commit hash. + A SHA256 hexdigest string of the git project's initial commit hash. If telemetry is opted out of by the user, or the `.git` folder is not found (the directory is not a git repository), returns None. """ @@ -105,5 +105,7 @@ def _parse_remote_origin_url(url: str) -> List[str]: def _encrypt_value(value: str) -> str: - """Encrypt a string, and then return the encrypted value as a string.""" - return str(uuid5(NAMESPACE_URL, value)) + """Encrypt a string, and then return the encrypted value as a byte string.""" + h = hashlib.sha256() + h.update(value.encode("utf-8")) + return h.hexdigest() diff --git a/tests/unit/lib/telemetry/test_project_metadata.py b/tests/unit/lib/telemetry/test_project_metadata.py index 8bd6f485c3..b165e912fa 100644 --- a/tests/unit/lib/telemetry/test_project_metadata.py +++ b/tests/unit/lib/telemetry/test_project_metadata.py @@ -2,8 +2,8 @@ Module for testing the project_metadata.py methods. """ +import hashlib from subprocess import CompletedProcess, CalledProcessError -from uuid import uuid5, NAMESPACE_URL from unittest.mock import patch, Mock from unittest import TestCase @@ -49,7 +49,9 @@ def test_retrieve_git_origin(self, origin, expected, sp_mock): sp_mock.return_value = CompletedProcess(["git", "config", "--get", "remote.origin.url"], 0, stdout=origin) git_origin = get_git_remote_origin_url() - self.assertEqual(git_origin, str(uuid5(NAMESPACE_URL, expected))) + expected_hash = hashlib.sha256() + expected_hash.update(expected.encode("utf-8")) + self.assertEqual(git_origin, expected_hash.hexdigest()) @patch("samcli.lib.telemetry.project_metadata.subprocess.run") def test_retrieve_git_origin_when_not_a_repo(self, sp_mock): @@ -73,7 +75,9 @@ def test_retrieve_project_name_from_git(self, origin, expected, sp_mock): sp_mock.return_value = CompletedProcess(["git", "config", "--get", "remote.origin.url"], 0, stdout=origin) project_name = get_project_name() - self.assertEqual(project_name, str(uuid5(NAMESPACE_URL, expected))) + expected_hash = hashlib.sha256() + expected_hash.update(expected.encode("utf-8")) + self.assertEqual(project_name, expected_hash.hexdigest()) @parameterized.expand( [ @@ -94,7 +98,9 @@ def test_retrieve_project_name_from_dir(self, cwd, sp_mock, cwd_mock): cwd_mock.return_value = cwd project_name = get_project_name() - self.assertEqual(project_name, str(uuid5(NAMESPACE_URL, cwd.replace("\\", "/")))) + expected_hash = hashlib.sha256() + expected_hash.update(cwd.replace("\\", "/").encode("utf-8")) + self.assertEqual(project_name, expected_hash.hexdigest()) @parameterized.expand( [ @@ -108,4 +114,6 @@ def test_retrieve_initial_commit(self, git_hash, sp_mock): sp_mock.return_value = CompletedProcess(["git", "rev-list", "--max-parents=0", "HEAD"], 0, stdout=git_hash) initial_commit = get_initial_commit_hash() - self.assertEqual(initial_commit, str(uuid5(NAMESPACE_URL, git_hash))) + expected_hash = hashlib.sha256() + expected_hash.update(git_hash.encode("utf-8")) + self.assertEqual(initial_commit, expected_hash.hexdigest()) From fda06ae52c3ca633b8276b840e056af0a9cfba6c Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Wed, 20 Jul 2022 11:32:24 -0700 Subject: [PATCH 13/23] Add long event tracker (#4067) --- samcli/lib/telemetry/event.py | 74 ++++++++++++++++++++++++++ tests/unit/lib/telemetry/test_event.py | 63 +++++++++++++++++++++- 2 files changed, 136 insertions(+), 1 deletion(-) diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index fe13481d77..f931041e18 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -173,5 +173,79 @@ def send_events(): EventTracker._events = [] # Manual clear_trackers() since we're within the lock +def track_long_event(start_event_name: str, start_event_value: str, end_event_name: str, end_event_value: str): + """Decorator for tracking events that occur at start and end of a function. + + The decorator tracks two Events total, where the first Event occurs + at the start of the decorated function's execution (prior to its + first line) and the second Event occurs after the function has ended + (after the final line of the function has executed). + + Parameters + ---------- + start_event_name: str + The name of the Event that is executed at the start of the + decorated function's execution. Must be a valid EventName + value or the decorator will not run. + start_event_value: str + The value of the Event that is executed at the start of the + decorated function's execution. Must be a valid EventType + value for the passed `start_event_name` or the decorator + will not run. + end_event_name: str + The name of the Event that is executed at the end of the + decorated function's execution. Must be a valid EventName + value or the decorator will not run. + end_event_value: str + The value of the Event that is executed at the end of the + decorated function's execution. Must be a valid EventType + value for the passed `end_event_name` or the decorator + will not run. + + Examples + -------- + >>> @track_long_event("FuncStart", "Func1", "FuncEnd", "Func1") + def func1(...): + # do things + + >>> @track_long_event("FuncStart", "Func2", "FuncEnd", "Func2") + def func2(...): + # do things + """ + should_track = True + try: + # Check that passed values are valid Events + Event(start_event_name, start_event_value) + Event(end_event_name, end_event_value) + except EventCreationError as e: + LOG.debug("Error occurred while trying to track an event: %s\nDecorator not run.", e) + should_track = False + + def decorator_for_events(func): + """The actual decorator""" + + def wrapped(*args, **kwargs): + if should_track: + EventTracker.track_event(start_event_name, start_event_value) + exception = None + + try: + return_value = func(*args, **kwargs) + except Exception as e: + exception = e + + if should_track: + EventTracker.track_event(end_event_name, end_event_value) + EventTracker.send_events() # Ensure Events are sent at the end of execution + if exception: + raise exception + + return return_value + + return wrapped + + return decorator_for_events + + class EventCreationError(Exception): """Exception called when an Event is not properly created.""" diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py index 9802b1b75a..a20f84c336 100644 --- a/tests/unit/lib/telemetry/test_event.py +++ b/tests/unit/lib/telemetry/test_event.py @@ -4,10 +4,11 @@ from enum import Enum import threading +from typing import List, Tuple from unittest import TestCase from unittest.mock import ANY, Mock, patch -from samcli.lib.telemetry.event import Event, EventCreationError, EventTracker +from samcli.lib.telemetry.event import Event, EventCreationError, EventTracker, track_long_event class DummyEventName(Enum): @@ -170,3 +171,63 @@ def make_mock_event(name, value): EventTracker.track_event("TheStrawThat", "BreaksTheCamel'sBack") send_mock.assert_called() + + +class TestTrackLongEvent(TestCase): + @patch("samcli.lib.telemetry.event.EventTracker.send_events") + @patch("samcli.lib.telemetry.event.EventTracker.track_event") + @patch("samcli.lib.telemetry.event.Event", return_value=None) + def test_long_event_is_tracked(self, event_mock, track_mock, send_mock): + mock_tracker = {} + mock_tracker["tracked_events"]: List[Tuple[str, str]] = [] # Tuple to bypass Event verification + mock_tracker["emitted_events"]: List[Tuple[str, str]] = [] + + def mock_track(name, value): + mock_tracker["tracked_events"].append((name, value)) + + def mock_send(): + mock_tracker["emitted_events"] = mock_tracker["tracked_events"] + mock_tracker["tracked_events"] = [] # Mimic clear_trackers() + + track_mock.side_effect = mock_track + send_mock.side_effect = mock_send + + @track_long_event("StartEvent", "StartValue", "EndEvent", "EndValue") + def func(): + self.assertEqual(len(mock_tracker["tracked_events"]), 1, "Starting event not tracked.") + self.assertIn(("StartEvent", "StartValue"), mock_tracker["tracked_events"], "Incorrect starting event.") + + func() + + self.assertEqual(len(mock_tracker["tracked_events"]), 0, "Tracked events not reset; send_events not called.") + self.assertEqual(len(mock_tracker["emitted_events"]), 2, "Unexpected number of emitted events.") + self.assertIn(("StartEvent", "StartValue"), mock_tracker["emitted_events"], "Starting event not tracked.") + self.assertIn(("EndEvent", "EndValue"), mock_tracker["emitted_events"], "Ending event not tracked.") + + @patch("samcli.lib.telemetry.event.EventTracker.send_events") + @patch("samcli.lib.telemetry.event.EventTracker.track_event") + def test_nothing_tracked_if_invalid_events(self, track_mock, send_mock): + mock_tracker = {} + mock_tracker["tracked_events"]: List[Tuple[str, str]] = [] # Tuple to bypass Event verification + mock_tracker["emitted_events"]: List[Tuple[str, str]] = [] + + def mock_track(name, value): + mock_tracker["tracked_events"].append((name, value)) + + def mock_send(): + mock_tracker["emitted_events"] = mock_tracker["tracked_events"] + mock_tracker["tracked_events"] = [] # Mimic clear_trackers() + + track_mock.side_effect = mock_track + send_mock.side_effect = mock_send + + @track_long_event("DefinitelyNotARealEvent", "Nope", "ThisEventDoesntExist", "NuhUh") + def func(): + self.assertEqual(len(mock_tracker["tracked_events"]), 0, "Events should not have been tracked.") + + func() + + self.assertEqual(len(mock_tracker["tracked_events"]), 0, "Events should not have been tracked.") + self.assertEqual(len(mock_tracker["emitted_events"]), 0, "Events should not have been emitted.") + track_mock.assert_not_called() # Tracker should not have been called + send_mock.assert_not_called() # Sender should not have been called From a5c3060e1f7bbcd8624c4ea4b5492805b6cfcd8f Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Fri, 22 Jul 2022 12:28:14 -0700 Subject: [PATCH 14/23] Send events via thread when at capacity (#4072) * Switch send_events to thread when at capacity * Repair failing unit test --- samcli/lib/telemetry/event.py | 3 ++- tests/unit/lib/telemetry/test_event.py | 6 ++++++ 2 files changed, 8 insertions(+), 1 deletion(-) diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index f931041e18..745764dcc7 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -139,7 +139,8 @@ def track_event(event_name: str, event_value: str): if len(EventTracker._events) >= EventTracker.MAX_EVENTS: should_send = True if should_send: - EventTracker.send_events() + send_thread = threading.Thread(target=EventTracker.send_events) + send_thread.start() except EventCreationError as e: LOG.debug("Error occurred while trying to track an event: %s", e) diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py index a20f84c336..24e6e29b1f 100644 --- a/tests/unit/lib/telemetry/test_event.py +++ b/tests/unit/lib/telemetry/test_event.py @@ -170,6 +170,12 @@ def make_mock_event(name, value): # Add one more event to trigger sending all events EventTracker.track_event("TheStrawThat", "BreaksTheCamel'sBack") + # Wait for all threads to complete + for thread in threading.enumerate(): + if thread is threading.main_thread(): + continue + thread.join() + send_mock.assert_called() From 9a597d731714e8831368e954c0d99abd1d804cf7 Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Thu, 28 Jul 2022 09:47:48 -0700 Subject: [PATCH 15/23] Add `sam sync` Events (#4076) * Add sam sync Events * Refactor methods for tracking sync events * Improve SyncFlow tracking * Add additional SyncFlow value --- samcli/commands/sync/command.py | 3 ++- samcli/lib/sync/sync_flow_executor.py | 10 ++++++++++ samcli/lib/telemetry/event.py | 23 +++++++++++++++++++++++ 3 files changed, 35 insertions(+), 1 deletion(-) diff --git a/samcli/commands/sync/command.py b/samcli/commands/sync/command.py index 8586a3bdbf..2184e83fa9 100644 --- a/samcli/commands/sync/command.py +++ b/samcli/commands/sync/command.py @@ -27,7 +27,7 @@ ) from samcli.cli.cli_config_file import configuration_option, TomlProvider from samcli.commands._utils.click_mutex import ClickMutex -from samcli.lib.telemetry.event import EventTracker +from samcli.lib.telemetry.event import EventTracker, track_long_event from samcli.lib.utils.colors import Colored from samcli.lib.utils.version_checker import check_newer_version from samcli.lib.bootstrap.bootstrap import manage_stack @@ -144,6 +144,7 @@ @capabilities_option(default=DEFAULT_CAPABILITIES) # pylint: disable=E1120 @experimental @pass_context +@track_long_event("SyncUsed", "Start", "SyncUsed", "End") @track_command @image_repository_validation @track_template_warnings([CodeDeployWarning.__name__, CodeDeployConditionWarning.__name__]) diff --git a/samcli/lib/sync/sync_flow_executor.py b/samcli/lib/sync/sync_flow_executor.py index 0cba6305cd..082a57c70d 100644 --- a/samcli/lib/sync/sync_flow_executor.py +++ b/samcli/lib/sync/sync_flow_executor.py @@ -10,6 +10,7 @@ from concurrent.futures import ThreadPoolExecutor, Future from botocore.exceptions import ClientError +from samcli.lib.telemetry.event import EventName, EventTracker, EventType from samcli.lib.utils.colors import Colored from samcli.lib.providers.exceptions import MissingLocalDefinition @@ -331,7 +332,13 @@ def _sync_flow_execute_wrapper(sync_flow: SyncFlow) -> SyncFlowResult: SyncFlowException """ dependent_sync_flows = [] + sync_types = EventType.get_accepted_values(EventName.SYNC_FLOW_START) + sync_type: Optional[str] = type(sync_flow).__name__ + if sync_type not in sync_types: + sync_type = None try: + if sync_type: + EventTracker.track_event("SyncFlowStart", sync_type) dependent_sync_flows = sync_flow.execute() except ClientError as e: if e.response.get("Error", dict()).get("Code", "") == "ResourceNotFoundException": @@ -339,4 +346,7 @@ def _sync_flow_execute_wrapper(sync_flow: SyncFlow) -> SyncFlowResult: raise SyncFlowException(sync_flow, e) from e except Exception as e: raise SyncFlowException(sync_flow, e) from e + finally: + if sync_type: + EventTracker.track_event("SyncFlowEnd", sync_type) return SyncFlowResult(sync_flow=sync_flow, dependent_sync_flows=dependent_sync_flows) diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index 745764dcc7..906b2d56a3 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -21,11 +21,28 @@ class EventName(Enum): USED_FEATURE = "UsedFeature" DEPLOY = "Deploy" BUILD_FUNCTION_RUNTIME = "BuildFunctionRuntime" + SYNC_USED = "SyncUsed" + SYNC_FLOW_START = "SyncFlowStart" + SYNC_FLOW_END = "SyncFlowEnd" class EventType: """Class for Events and the types of values they may have.""" + _SYNC_FLOWS = [ + "AliasVersionSyncFlow", + "AutoDependencyLayerSyncFlow", + "AutoDependencyLayerParentSyncFlow", + "FunctionSyncFlow", + "FunctionLayerReferenceSync", + "GenericApiSyncFlow", + "HttpApiSyncFlow", + "ImageFunctionSyncFlow", + "LayerSyncFlow", + "RestApiSyncFlow", + "StepFunctionsSyncFlow", + "ZipFunctionSyncFlow", + ] _events = { EventName.USED_FEATURE: [ "ESBuild", @@ -39,6 +56,12 @@ class EventType: "CreateChangeSetSuccess", ], EventName.BUILD_FUNCTION_RUNTIME: INIT_RUNTIMES, + EventName.SYNC_USED: [ + "Start", + "End", + ], + EventName.SYNC_FLOW_START: _SYNC_FLOWS, + EventName.SYNC_FLOW_END: _SYNC_FLOWS, } @staticmethod From 1b0288844a6f6a8505d4164da13d496b12bc8f76 Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Mon, 8 Aug 2022 16:30:04 -0700 Subject: [PATCH 16/23] Add workflow events (#4096) * Add workflow_config events * Refactor workflow Events * Add tests for verifying workflow events * Remove redundant (UsedFeature, ESBuild) event * Repair failing unit test * Rename workflow event to prevent ambiguity --- samcli/commands/build/build_context.py | 2 - samcli/lib/build/workflow_config.py | 102 +++--------------- samcli/lib/build/workflows.py | 102 ++++++++++++++++++ samcli/lib/telemetry/event.py | 12 +-- .../lib/build_module/test_workflow_config.py | 17 +++ tests/unit/lib/telemetry/test_event.py | 3 + 6 files changed, 143 insertions(+), 95 deletions(-) create mode 100644 samcli/lib/build/workflows.py diff --git a/samcli/commands/build/build_context.py b/samcli/commands/build/build_context.py index dc5b6726f3..7f1f5bff4b 100644 --- a/samcli/commands/build/build_context.py +++ b/samcli/commands/build/build_context.py @@ -270,8 +270,6 @@ def run(self): for f in self.get_resources_to_build().functions: EventTracker.track_event("BuildFunctionRuntime", f.runtime) - if f.metadata and f.metadata.get("BuildMethod", "") == "esbuild": - EventTracker.track_event("UsedFeature", "ESBuild") click.secho("\nBuild Succeeded", fg="green") diff --git a/samcli/lib/build/workflow_config.py b/samcli/lib/build/workflow_config.py index 3a006ca2e4..d6b1f55926 100644 --- a/samcli/lib/build/workflow_config.py +++ b/samcli/lib/build/workflow_config.py @@ -4,95 +4,24 @@ import os import logging -from collections import namedtuple from typing import Dict, List, Optional, Tuple, Union, cast -LOG = logging.getLogger(__name__) - -CONFIG = namedtuple( - "Capability", - ["language", "dependency_manager", "application_framework", "manifest_name", "executable_search_paths"], -) - -PYTHON_PIP_CONFIG = CONFIG( - language="python", - dependency_manager="pip", - application_framework=None, - manifest_name="requirements.txt", - executable_search_paths=None, -) - -NODEJS_NPM_CONFIG = CONFIG( - language="nodejs", - dependency_manager="npm", - application_framework=None, - manifest_name="package.json", - executable_search_paths=None, -) - -RUBY_BUNDLER_CONFIG = CONFIG( - language="ruby", - dependency_manager="bundler", - application_framework=None, - manifest_name="Gemfile", - executable_search_paths=None, -) - -JAVA_GRADLE_CONFIG = CONFIG( - language="java", - dependency_manager="gradle", - application_framework=None, - manifest_name="build.gradle", - executable_search_paths=None, -) - -JAVA_KOTLIN_GRADLE_CONFIG = CONFIG( - language="java", - dependency_manager="gradle", - application_framework=None, - manifest_name="build.gradle.kts", - executable_search_paths=None, +from samcli.lib.build.workflows import ( + CONFIG, + PYTHON_PIP_CONFIG, + NODEJS_NPM_CONFIG, + RUBY_BUNDLER_CONFIG, + JAVA_GRADLE_CONFIG, + JAVA_KOTLIN_GRADLE_CONFIG, + JAVA_MAVEN_CONFIG, + DOTNET_CLIPACKAGE_CONFIG, + GO_MOD_CONFIG, + PROVIDED_MAKE_CONFIG, + NODEJS_NPM_ESBUILD_CONFIG, ) +from samcli.lib.telemetry.event import EventTracker -JAVA_MAVEN_CONFIG = CONFIG( - language="java", - dependency_manager="maven", - application_framework=None, - manifest_name="pom.xml", - executable_search_paths=None, -) - -DOTNET_CLIPACKAGE_CONFIG = CONFIG( - language="dotnet", - dependency_manager="cli-package", - application_framework=None, - manifest_name=".csproj", - executable_search_paths=None, -) - -GO_MOD_CONFIG = CONFIG( - language="go", - dependency_manager="modules", - application_framework=None, - manifest_name="go.mod", - executable_search_paths=None, -) - -PROVIDED_MAKE_CONFIG = CONFIG( - language="provided", - dependency_manager=None, - application_framework=None, - manifest_name="Makefile", - executable_search_paths=None, -) - -NODEJS_NPM_ESBUILD_CONFIG = CONFIG( - language="nodejs", - dependency_manager="npm-esbuild", - application_framework=None, - manifest_name="package.json", - executable_search_paths=None, -) +LOG = logging.getLogger(__name__) class UnsupportedRuntimeException(Exception): @@ -278,6 +207,9 @@ def get_workflow_config( # Identify workflow configuration from the workflow selector. config = cast(WorkFlowSelector, selector).get_config(code_dir, project_dir) + + EventTracker.track_event("BuildWorkflowUsed", f"{config.language}-{config.dependency_manager}") + return config except ValueError as ex: raise UnsupportedRuntimeException( diff --git a/samcli/lib/build/workflows.py b/samcli/lib/build/workflows.py new file mode 100644 index 0000000000..a413f696c1 --- /dev/null +++ b/samcli/lib/build/workflows.py @@ -0,0 +1,102 @@ +"""Module for storing information about existing workflows.""" + +from collections import namedtuple +from typing import List + +CONFIG = namedtuple( + "Capability", + ["language", "dependency_manager", "application_framework", "manifest_name", "executable_search_paths"], +) + +PYTHON_PIP_CONFIG = CONFIG( + language="python", + dependency_manager="pip", + application_framework=None, + manifest_name="requirements.txt", + executable_search_paths=None, +) + +NODEJS_NPM_CONFIG = CONFIG( + language="nodejs", + dependency_manager="npm", + application_framework=None, + manifest_name="package.json", + executable_search_paths=None, +) + +RUBY_BUNDLER_CONFIG = CONFIG( + language="ruby", + dependency_manager="bundler", + application_framework=None, + manifest_name="Gemfile", + executable_search_paths=None, +) + +JAVA_GRADLE_CONFIG = CONFIG( + language="java", + dependency_manager="gradle", + application_framework=None, + manifest_name="build.gradle", + executable_search_paths=None, +) + +JAVA_KOTLIN_GRADLE_CONFIG = CONFIG( + language="java", + dependency_manager="gradle", + application_framework=None, + manifest_name="build.gradle.kts", + executable_search_paths=None, +) + +JAVA_MAVEN_CONFIG = CONFIG( + language="java", + dependency_manager="maven", + application_framework=None, + manifest_name="pom.xml", + executable_search_paths=None, +) + +DOTNET_CLIPACKAGE_CONFIG = CONFIG( + language="dotnet", + dependency_manager="cli-package", + application_framework=None, + manifest_name=".csproj", + executable_search_paths=None, +) + +GO_MOD_CONFIG = CONFIG( + language="go", + dependency_manager="modules", + application_framework=None, + manifest_name="go.mod", + executable_search_paths=None, +) + +PROVIDED_MAKE_CONFIG = CONFIG( + language="provided", + dependency_manager=None, + application_framework=None, + manifest_name="Makefile", + executable_search_paths=None, +) + +NODEJS_NPM_ESBUILD_CONFIG = CONFIG( + language="nodejs", + dependency_manager="npm-esbuild", + application_framework=None, + manifest_name="package.json", + executable_search_paths=None, +) + +ALL_CONFIGS: List[CONFIG] = [ + PYTHON_PIP_CONFIG, + NODEJS_NPM_CONFIG, + RUBY_BUNDLER_CONFIG, + JAVA_GRADLE_CONFIG, + JAVA_KOTLIN_GRADLE_CONFIG, + JAVA_MAVEN_CONFIG, + DOTNET_CLIPACKAGE_CONFIG, + GO_MOD_CONFIG, + PROVIDED_MAKE_CONFIG, + NODEJS_NPM_ESBUILD_CONFIG, +] diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index 906b2d56a3..2ddaf39b15 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -8,6 +8,7 @@ import threading from typing import List +from samcli.lib.build.workflows import ALL_CONFIGS from samcli.lib.telemetry.telemetry import Telemetry from samcli.local.common.runtime_template import INIT_RUNTIMES @@ -19,11 +20,11 @@ class EventName(Enum): """Enum for the names of available events to track.""" USED_FEATURE = "UsedFeature" - DEPLOY = "Deploy" BUILD_FUNCTION_RUNTIME = "BuildFunctionRuntime" SYNC_USED = "SyncUsed" SYNC_FLOW_START = "SyncFlowStart" SYNC_FLOW_END = "SyncFlowEnd" + BUILD_WORKFLOW_USED = "BuildWorkflowUsed" class EventType: @@ -43,18 +44,12 @@ class EventType: "StepFunctionsSyncFlow", "ZipFunctionSyncFlow", ] + _WORKFLOWS = [f"{config.language}-{config.dependency_manager}" for config in ALL_CONFIGS] _events = { EventName.USED_FEATURE: [ - "ESBuild", "Accelerate", "CDK", ], - EventName.DEPLOY: [ - "CreateChangeSetStart", - "CreateChangeSetInProgress", - "CreateChangeSetFailed", - "CreateChangeSetSuccess", - ], EventName.BUILD_FUNCTION_RUNTIME: INIT_RUNTIMES, EventName.SYNC_USED: [ "Start", @@ -62,6 +57,7 @@ class EventType: ], EventName.SYNC_FLOW_START: _SYNC_FLOWS, EventName.SYNC_FLOW_END: _SYNC_FLOWS, + EventName.BUILD_WORKFLOW_USED: _WORKFLOWS, } @staticmethod diff --git a/tests/unit/lib/build_module/test_workflow_config.py b/tests/unit/lib/build_module/test_workflow_config.py index 52549a3718..e35d6c05fe 100644 --- a/tests/unit/lib/build_module/test_workflow_config.py +++ b/tests/unit/lib/build_module/test_workflow_config.py @@ -7,12 +7,14 @@ UnsupportedRuntimeException, UnsupportedBuilderException, ) +from samcli.lib.telemetry.event import Event, EventTracker class Test_get_workflow_config(TestCase): def setUp(self): self.code_dir = "" self.project_dir = "" + EventTracker.clear_trackers() @parameterized.expand([("python3.6",), ("python3.7",), ("python3.8",)]) def test_must_work_for_python(self, runtime): @@ -23,6 +25,8 @@ def test_must_work_for_python(self, runtime): self.assertEqual(result.application_framework, None) self.assertEqual(result.manifest_name, "requirements.txt") self.assertIsNone(result.executable_search_paths) + self.assertEqual(len(EventTracker.get_tracked_events()), 1) + self.assertIn(Event("BuildWorkflowUsed", "python-pip"), EventTracker.get_tracked_events()) @parameterized.expand([("nodejs12.x",), ("nodejs14.x",), ("nodejs16.x",)]) def test_must_work_for_nodejs(self, runtime): @@ -33,6 +37,8 @@ def test_must_work_for_nodejs(self, runtime): self.assertEqual(result.application_framework, None) self.assertEqual(result.manifest_name, "package.json") self.assertIsNone(result.executable_search_paths) + self.assertEqual(len(EventTracker.get_tracked_events()), 1) + self.assertIn(Event("BuildWorkflowUsed", "nodejs-npm"), EventTracker.get_tracked_events()) @parameterized.expand([("provided",)]) def test_must_work_for_provided(self, runtime): @@ -42,6 +48,8 @@ def test_must_work_for_provided(self, runtime): self.assertEqual(result.application_framework, None) self.assertEqual(result.manifest_name, "Makefile") self.assertIsNone(result.executable_search_paths) + self.assertEqual(len(EventTracker.get_tracked_events()), 1) + self.assertIn(Event("BuildWorkflowUsed", "provided-None"), EventTracker.get_tracked_events()) @parameterized.expand([("provided",)]) def test_must_work_for_provided_with_no_specified_workflow(self, runtime): @@ -52,6 +60,8 @@ def test_must_work_for_provided_with_no_specified_workflow(self, runtime): self.assertEqual(result.application_framework, None) self.assertEqual(result.manifest_name, "Makefile") self.assertIsNone(result.executable_search_paths) + self.assertEqual(len(EventTracker.get_tracked_events()), 1) + self.assertIn(Event("BuildWorkflowUsed", "provided-None"), EventTracker.get_tracked_events()) @parameterized.expand([("provided",)]) def test_raise_exception_for_bad_specified_workflow(self, runtime): @@ -66,6 +76,8 @@ def test_must_work_for_ruby(self, runtime): self.assertEqual(result.application_framework, None) self.assertEqual(result.manifest_name, "Gemfile") self.assertIsNone(result.executable_search_paths) + self.assertEqual(len(EventTracker.get_tracked_events()), 1) + self.assertIn(Event("BuildWorkflowUsed", "ruby-bundler"), EventTracker.get_tracked_events()) @parameterized.expand( [("java8", "build.gradle", "gradle"), ("java8", "build.gradle.kts", "gradle"), ("java8", "pom.xml", "maven")] @@ -80,11 +92,14 @@ def test_must_work_for_java(self, runtime, build_file, dep_manager, os_mock): self.assertEqual(result.dependency_manager, dep_manager) self.assertEqual(result.application_framework, None) self.assertEqual(result.manifest_name, build_file) + self.assertEqual(len(EventTracker.get_tracked_events()), 1) if dep_manager == "gradle": self.assertEqual(result.executable_search_paths, [self.code_dir, self.project_dir]) + self.assertIn(Event("BuildWorkflowUsed", "java-gradle"), EventTracker.get_tracked_events()) else: self.assertIsNone(result.executable_search_paths) + self.assertIn(Event("BuildWorkflowUsed", "java-maven"), EventTracker.get_tracked_events()) def test_must_get_workflow_for_esbuild(self): runtime = "nodejs12.x" @@ -94,6 +109,8 @@ def test_must_get_workflow_for_esbuild(self): self.assertEqual(result.application_framework, None) self.assertEqual(result.manifest_name, "package.json") self.assertIsNone(result.executable_search_paths) + self.assertEqual(len(EventTracker.get_tracked_events()), 1) + self.assertIn(Event("BuildWorkflowUsed", "nodejs-npm-esbuild"), EventTracker.get_tracked_events()) @parameterized.expand([("java8", "unknown.manifest")]) @patch("samcli.lib.build.workflow_config.os") diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py index 24e6e29b1f..68d70b4680 100644 --- a/tests/unit/lib/telemetry/test_event.py +++ b/tests/unit/lib/telemetry/test_event.py @@ -69,6 +69,9 @@ def test_event_to_json(self, name_mock, type_mock, verify_mock): class TestEventTracker(TestCase): + def setUp(self): + EventTracker.clear_trackers() + @patch("samcli.lib.telemetry.event.EventTracker._event_lock") @patch("samcli.lib.telemetry.event.Event") def test_track_event(self, event_mock, lock_mock): From 790e078ad67fc96e98678a12fd3154651d0da4c2 Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Wed, 10 Aug 2022 10:59:13 -0700 Subject: [PATCH 17/23] Fix send_events logic (#4104) --- samcli/lib/telemetry/event.py | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index 2ddaf39b15..283401ef98 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -179,19 +179,20 @@ def send_events(): """Sends the current list of events via Telemetry.""" from samcli.lib.telemetry.metric import Metric # pylint: disable=cyclic-import + msa = {} + with EventTracker._event_lock: if not EventTracker._events: # Don't do anything if there are no events to send return - telemetry = Telemetry() - - metric = Metric("events") - msa = {} msa["events"] = [e.to_json() for e in EventTracker._events] - metric.add_data("metricSpecificAttributes", msa) - telemetry.emit(metric) EventTracker._events = [] # Manual clear_trackers() since we're within the lock + telemetry = Telemetry() + metric = Metric("events") + metric.add_data("metricSpecificAttributes", msa) + telemetry.emit(metric) + def track_long_event(start_event_name: str, start_event_value: str, end_event_name: str, end_event_value: str): """Decorator for tracking events that occur at start and end of a function. From e46d19aea93bb7dc3cf9ec1b958c4ae05c8d964a Mon Sep 17 00:00:00 2001 From: Leonardo Gama <51037424+Leo10Gama@users.noreply.github.com> Date: Mon, 15 Aug 2022 14:59:07 -0700 Subject: [PATCH 18/23] Make minor tweaks before launch (#4111) * Apply minor changes (some major) * Add session_id for multithreaded send_events * Adjust tests for new multithreading * Fix failing integration test * *Actually* fix failing integration test * Properly fix integration test * This time for sure * Really really repair that test * OK this one SHOULD work I swear * This time for sure * FIX INTEGRATION TEST * IT'S A LIST * Remove unused imports * Add debug log for EventTracker session ID * Place debug log in better position --- samcli/commands/sync/command.py | 2 +- samcli/lib/telemetry/event.py | 45 ++++++++++++++----- .../telemetry/test_experimental_metric.py | 5 ++- tests/unit/lib/telemetry/test_event.py | 6 ++- 4 files changed, 44 insertions(+), 14 deletions(-) diff --git a/samcli/commands/sync/command.py b/samcli/commands/sync/command.py index b293bbd081..8f63c7e743 100644 --- a/samcli/commands/sync/command.py +++ b/samcli/commands/sync/command.py @@ -132,8 +132,8 @@ @tags_option @capabilities_option(default=DEFAULT_CAPABILITIES) # pylint: disable=E1120 @pass_context -@track_long_event("SyncUsed", "Start", "SyncUsed", "End") @track_command +@track_long_event("SyncUsed", "Start", "SyncUsed", "End") @image_repository_validation @track_template_warnings([CodeDeployWarning.__name__, CodeDeployConditionWarning.__name__]) @check_newer_version diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index 283401ef98..f04a0aaf26 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -6,8 +6,9 @@ from enum import Enum import logging import threading -from typing import List +from typing import List, Optional +from samcli.cli.context import Context from samcli.lib.build.workflows import ALL_CONFIGS from samcli.lib.telemetry.telemetry import Telemetry from samcli.local.common.runtime_template import INIT_RUNTIMES @@ -45,7 +46,8 @@ class EventType: "ZipFunctionSyncFlow", ] _WORKFLOWS = [f"{config.language}-{config.dependency_manager}" for config in ALL_CONFIGS] - _events = { + + _event_values = { # Contains allowable values for Events EventName.USED_FEATURE: [ "Accelerate", "CDK", @@ -63,9 +65,9 @@ class EventType: @staticmethod def get_accepted_values(event_name: EventName) -> List[str]: """Get all acceptable values for a given Event name.""" - if event_name not in EventType._events: + if event_name not in EventType._event_values: return [] - return EventType._events[event_name] + return EventType._event_values[event_name] class Event: @@ -120,6 +122,7 @@ class EventTracker: _events: List[Event] = [] _event_lock = threading.Lock() + _session_id: Optional[str] = None MAX_EVENTS: int = 50 # Maximum number of events to store before sending @@ -155,16 +158,24 @@ def track_event(event_name: str, event_value: str): should_send: bool = False with EventTracker._event_lock: EventTracker._events.append(Event(event_name, event_value)) + # Get the session ID (needed for multithreading sending) + if not EventTracker._session_id: + try: + ctx = Context.get_current_context() + if ctx: + EventTracker._session_id = ctx.session_id + except RuntimeError: + LOG.debug("EventTracker: Unable to obtain session ID") if len(EventTracker._events) >= EventTracker.MAX_EVENTS: should_send = True if should_send: - send_thread = threading.Thread(target=EventTracker.send_events) - send_thread.start() + EventTracker.send_events() except EventCreationError as e: LOG.debug("Error occurred while trying to track an event: %s", e) @staticmethod def get_tracked_events() -> List[Event]: + """Retrieve a list of all currently tracked Events.""" with EventTracker._event_lock: return EventTracker._events @@ -175,8 +186,15 @@ def clear_trackers(): EventTracker._events = [] @staticmethod - def send_events(): - """Sends the current list of events via Telemetry.""" + def send_events() -> threading.Thread: + """Call a thread to send the current list of Events via Telemetry.""" + send_thread = threading.Thread(target=EventTracker._send_events_in_thread) + send_thread.start() + return send_thread + + @staticmethod + def _send_events_in_thread(): + """Send the current list of Events via Telemetry.""" from samcli.lib.telemetry.metric import Metric # pylint: disable=cyclic-import msa = {} @@ -190,6 +208,7 @@ def send_events(): telemetry = Telemetry() metric = Metric("events") + metric.add_data("sessionId", EventTracker._session_id) metric.add_data("metricSpecificAttributes", msa) telemetry.emit(metric) @@ -201,6 +220,11 @@ def track_long_event(start_event_name: str, start_event_value: str, end_event_na at the start of the decorated function's execution (prior to its first line) and the second Event occurs after the function has ended (after the final line of the function has executed). + If this decorator is being placed in a function that also contains the + `track_command` decorator, ensure that this decorator is placed BELOW + `track_command`. Otherwise, the current list of Events will be sent + before the end_event will be added, resulting in an additional 'events' + metric with only that single Event. Parameters ---------- @@ -246,15 +270,16 @@ def decorator_for_events(func): """The actual decorator""" def wrapped(*args, **kwargs): + # Track starting event if should_track: EventTracker.track_event(start_event_name, start_event_value) exception = None - + # Run the function try: return_value = func(*args, **kwargs) except Exception as e: exception = e - + # Track ending event if should_track: EventTracker.track_event(end_event_name, end_event_value) EventTracker.send_events() # Ensure Events are sent at the end of execution diff --git a/tests/integration/telemetry/test_experimental_metric.py b/tests/integration/telemetry/test_experimental_metric.py index 72eddd0aa1..977e65053f 100644 --- a/tests/integration/telemetry/test_experimental_metric.py +++ b/tests/integration/telemetry/test_experimental_metric.py @@ -158,7 +158,10 @@ def test_must_send_cdk_project_type_metrics(self): all_requests = server.get_all_requests() self.assertGreaterEqual(len(all_requests), 1, "Command run metric must be sent") - request = all_requests[-1] # commandRun metric is last bc of ordering 'send_events' vs 'telemetry.emit' + request = all_requests[0] + for req in all_requests: + if "commandRun" in req["data"]["metrics"][0]: + request = req # We're only testing the commandRun metric self.assertIn("Content-Type", request["headers"]) self.assertEqual(request["headers"]["Content-Type"], "application/json") diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py index 68d70b4680..f566a68554 100644 --- a/tests/unit/lib/telemetry/test_event.py +++ b/tests/unit/lib/telemetry/test_event.py @@ -109,7 +109,9 @@ def test_events_get_sent(self, telemetry_mock): telemetry_mock.return_value = dummy_telemetry # Verify that no events are sent if tracker is empty - EventTracker.send_events() + # Note we are using the in-line version of the method, as the regular send_events will + # simply call this method in a new thread + EventTracker._send_events_in_thread() self.assertEqual(emitted_events, []) # No events should have been collected dummy_telemetry.emit.assert_not_called() # Nothing should have been sent (empty list) @@ -121,7 +123,7 @@ def test_events_get_sent(self, telemetry_mock): dummy_event.to_json.return_value = Event.to_json(dummy_event) EventTracker._events.append(dummy_event) - EventTracker.send_events() + EventTracker._send_events_in_thread() dummy_telemetry.emit.assert_called() self.assertEqual(len(emitted_events), 1) # The list of metrics (1) is copied into emitted_events From b61e7c8c058d701a26c9f6bf7c93659980479f18 Mon Sep 17 00:00:00 2001 From: Leonardo Gama Date: Tue, 16 May 2023 11:02:47 -0700 Subject: [PATCH 19/23] Fix thread ID bug in EventTracker --- samcli/lib/sync/sync_flow_executor.py | 7 +++-- samcli/lib/telemetry/event.py | 38 ++++++++++++++++++------ tests/unit/lib/telemetry/test_event.py | 41 ++++++++++++++++++++------ 3 files changed, 66 insertions(+), 20 deletions(-) diff --git a/samcli/lib/sync/sync_flow_executor.py b/samcli/lib/sync/sync_flow_executor.py index 0b0f09c868..2c68ca2732 100644 --- a/samcli/lib/sync/sync_flow_executor.py +++ b/samcli/lib/sync/sync_flow_executor.py @@ -6,6 +6,8 @@ from queue import Queue from threading import RLock from typing import Callable, List, Optional, Set +from concurrent.futures import ThreadPoolExecutor, Future +from uuid import uuid4 from botocore.exceptions import ClientError from samcli.lib.telemetry.event import EventName, EventTracker, EventType @@ -337,11 +339,12 @@ def _sync_flow_execute_wrapper(sync_flow: SyncFlow) -> SyncFlowResult: dependent_sync_flows = [] sync_types = EventType.get_accepted_values(EventName.SYNC_FLOW_START) sync_type: Optional[str] = type(sync_flow).__name__ + thread_id = uuid4() if sync_type not in sync_types: sync_type = None try: if sync_type: - EventTracker.track_event("SyncFlowStart", sync_type) + EventTracker.track_event("SyncFlowStart", sync_type, thread_id=thread_id) dependent_sync_flows = sync_flow.execute() except ClientError as e: if e.response.get("Error", dict()).get("Code", "") == "ResourceNotFoundException": @@ -351,5 +354,5 @@ def _sync_flow_execute_wrapper(sync_flow: SyncFlow) -> SyncFlowResult: raise SyncFlowException(sync_flow, e) from e finally: if sync_type: - EventTracker.track_event("SyncFlowEnd", sync_type) + EventTracker.track_event("SyncFlowEnd", sync_type, thread_id=thread_id) return SyncFlowResult(sync_flow=sync_flow, dependent_sync_flows=dependent_sync_flows) diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index ef21a00d1e..4cc6301bca 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -7,6 +7,7 @@ from datetime import datetime from enum import Enum from typing import List, Optional +from uuid import UUID, uuid4 from samcli.cli.context import Context from samcli.lib.build.workflows import ALL_CONFIGS @@ -83,14 +84,17 @@ class Event: event_name: EventName event_value: str # Validated by EventType.get_accepted_values to never be an arbitrary string - thread_id = threading.get_ident() # The thread ID; used to group Events from the same command run + thread_id: Optional[UUID] # The thread ID; used to group Events from the same command run time_stamp: str exception_name: Optional[str] - def __init__(self, event_name: str, event_value: str, exception_name: Optional[str] = None): + def __init__(self, event_name: str, event_value: str, thread_id: Optional[UUID] = None, exception_name: Optional[str] = None): Event._verify_event(event_name, event_value) self.event_name = EventName(event_name) self.event_value = event_value + if not thread_id: + thread_id = uuid4() + self.thread_id = thread_id self.time_stamp = str(datetime.utcnow())[:-3] # format microseconds from 6 -> 3 figures to allow SQL casting self.exception_name = exception_name @@ -105,7 +109,7 @@ def __repr__(self): return ( f"Event(event_name={self.event_name.value}, " f"event_value={self.event_value}, " - f"thread_id={self.thread_id}, " + f"thread_id={self.thread_id.hex}, " f"time_stamp={self.time_stamp})", f"exception_name={self.exception_name})", ) @@ -114,7 +118,7 @@ def to_json(self): return { "event_name": self.event_name.value, "event_value": self.event_value, - "thread_id": self.thread_id, + "thread_id": self.thread_id.hex, "time_stamp": self.time_stamp, "exception_name": self.exception_name, } @@ -144,7 +148,7 @@ class EventTracker: @staticmethod def track_event( - event_name: str, event_value: str, session_id: Optional[str] = None, exception_name: Optional[str] = None + event_name: str, event_value: str, session_id: Optional[str] = None, thread_id: Optional[UUID] = None, exception_name: Optional[str] = None ): """Method to track an event where and when it occurs. @@ -162,6 +166,8 @@ def track_event( passed event_name, or an EventCreationError will be thrown. session_id: Optional[str] The session ID to set to link back to the original command run + thread_id: Optional[UUID] + The thread ID of the Event to track, as a UUID. exception_name: Optional[str] The name of the exception that this event encountered when tracking a feature @@ -182,8 +188,11 @@ def track_event( try: should_send: bool = False + # Validate the thread ID + if not thread_id: # Passed value is not a UUID or None + thread_id = uuid4() with EventTracker._event_lock: - EventTracker._events.append(Event(event_name, event_value, exception_name=exception_name)) + EventTracker._events.append(Event(event_name, event_value, thread_id=thread_id, exception_name=exception_name)) # Get the session ID (needed for multithreading sending) EventTracker._set_session_id() @@ -248,7 +257,13 @@ def _send_events_in_thread(): telemetry.emit(metric) -def track_long_event(start_event_name: str, start_event_value: str, end_event_name: str, end_event_value: str): +def track_long_event( + start_event_name: str, + start_event_value: str, + end_event_name: str, + end_event_value: str, + thread_id: Optional[UUID] = None, +): """Decorator for tracking events that occur at start and end of a function. The decorator tracks two Events total, where the first Event occurs @@ -281,6 +296,8 @@ def track_long_event(start_event_name: str, start_event_value: str, end_event_na decorated function's execution. Must be a valid EventType value for the passed `end_event_name` or the decorator will not run. + thread_id: Optional[UUID] + The thread ID of the Events to track, as a UUID. Examples -------- @@ -297,6 +314,9 @@ def func2(...): # Check that passed values are valid Events Event(start_event_name, start_event_value) Event(end_event_name, end_event_value) + # Validate the thread ID + if not thread_id: # Passed value is not a UUID or None + thread_id = uuid4() except EventCreationError as e: LOG.debug("Error occurred while trying to track an event: %s\nDecorator not run.", e) should_track = False @@ -307,7 +327,7 @@ def decorator_for_events(func): def wrapped(*args, **kwargs): # Track starting event if should_track: - EventTracker.track_event(start_event_name, start_event_value) + EventTracker.track_event(start_event_name, start_event_value, thread_id=thread_id) exception = None # Run the function try: @@ -316,7 +336,7 @@ def wrapped(*args, **kwargs): exception = e # Track ending event if should_track: - EventTracker.track_event(end_event_name, end_event_value) + EventTracker.track_event(end_event_name, end_event_value, thread_id=thread_id) EventTracker.send_events() # Ensure Events are sent at the end of execution if exception: raise exception diff --git a/tests/unit/lib/telemetry/test_event.py b/tests/unit/lib/telemetry/test_event.py index 5738743788..b8dc01fd34 100644 --- a/tests/unit/lib/telemetry/test_event.py +++ b/tests/unit/lib/telemetry/test_event.py @@ -8,6 +8,7 @@ from unittest import TestCase from unittest.mock import ANY, Mock, patch from samcli.cli.context import Context +from uuid import UUID, uuid4 from samcli.lib.telemetry.event import Event, EventCreationError, EventTracker, track_long_event @@ -26,13 +27,32 @@ def test_create_event_exists(self, name_mock, type_mock, verify_mock): name_mock.return_value = Mock(value="TestOne") type_mock.get_accepted_values.return_value = ["value1", "value2"] verify_mock.return_value = None + thread_id = uuid4() + + test_event = Event("TestOne", "value1", thread_id) + + name_mock.assert_called_once() + self.assertEqual(test_event.event_name.value, "TestOne") + self.assertEqual(test_event.event_value, "value1") + self.assertEqual(test_event.thread_id, thread_id) # Should be on the same thread + + @patch("samcli.lib.telemetry.event.uuid4") + @patch("samcli.lib.telemetry.event.Event._verify_event") + @patch("samcli.lib.telemetry.event.EventType") + @patch("samcli.lib.telemetry.event.EventName") + def test_create_event_exists_no_thread_id(self, name_mock, type_mock, verify_mock, uuid_mock): + name_mock.return_value = Mock(value="TestOne") + type_mock.get_accepted_values.return_value = ["value1", "value2"] + verify_mock.return_value = None + thread_id = uuid4() + uuid_mock.return_value = thread_id test_event = Event("TestOne", "value1") name_mock.assert_called_once() self.assertEqual(test_event.event_name.value, "TestOne") self.assertEqual(test_event.event_value, "value1") - self.assertEqual(test_event.thread_id, threading.get_ident()) # Should be on the same thread + self.assertEqual(test_event.thread_id, thread_id) @patch("samcli.lib.telemetry.event.EventType") @patch("samcli.lib.telemetry.event.EventName") @@ -60,15 +80,16 @@ def test_event_to_json(self, name_mock, type_mock, verify_mock): name_mock.return_value = Mock(value="Testing") type_mock.get_accepted_values.return_value = ["value1"] verify_mock.return_value = None + thread_id = uuid4() - test_event = Event("Testing", "value1") + test_event = Event("Testing", "value1", thread_id) self.assertEqual( test_event.to_json(), { "event_name": "Testing", "event_value": "value1", - "thread_id": threading.get_ident(), + "thread_id": thread_id.hex, "time_stamp": ANY, "exception_name": None, }, @@ -86,7 +107,7 @@ def test_track_event(self, event_mock, lock_mock): lock_mock.__exit__ = Mock() # Test that an event can be tracked - dummy_event = Mock(event_name="Test", event_value="SomeValue", thread_id=threading.get_ident(), timestamp=ANY) + dummy_event = Mock(event_name="Test", event_value="SomeValue", thread_id=uuid4(), timestamp=ANY) event_mock.return_value = dummy_event EventTracker.track_event("Test", "SomeValue") @@ -114,6 +135,7 @@ def test_events_get_sent(self, telemetry_mock): dummy_telemetry.emit.return_value = None dummy_telemetry.emit.side_effect = mock_emit telemetry_mock.return_value = dummy_telemetry + thread_id = uuid4() # Verify that no events are sent if tracker is empty # Note we are using the in-line version of the method, as the regular send_events will @@ -124,9 +146,7 @@ def test_events_get_sent(self, telemetry_mock): dummy_telemetry.emit.assert_not_called() # Nothing should have been sent (empty list) # Verify that events get sent when they exist in tracker - dummy_event = Mock( - event_name=Mock(value="Test"), event_value="SomeValue", thread_id=threading.get_ident(), time_stamp=ANY - ) + dummy_event = Mock(event_name=Mock(value="Test"), event_value="SomeValue", thread_id=thread_id, time_stamp=ANY) dummy_event.to_json.return_value = Event.to_json(dummy_event) EventTracker._events.append(dummy_event) @@ -148,7 +168,7 @@ def test_events_get_sent(self, telemetry_mock): { "event_name": "Test", "event_value": "SomeValue", - "thread_id": ANY, + "thread_id": thread_id.hex, "time_stamp": ANY, "exception_name": ANY, } @@ -205,9 +225,11 @@ def test_long_event_is_tracked(self, event_mock, track_mock, send_mock): mock_tracker = {} mock_tracker["tracked_events"]: List[Tuple[str, str]] = [] # Tuple to bypass Event verification mock_tracker["emitted_events"]: List[Tuple[str, str]] = [] + tracked_threads: List[UUID] = [] - def mock_track(name, value): + def mock_track(name, value, thread_id): mock_tracker["tracked_events"].append((name, value)) + tracked_threads.append(thread_id) def mock_send(): mock_tracker["emitted_events"] = mock_tracker["tracked_events"] @@ -227,6 +249,7 @@ def func(): self.assertEqual(len(mock_tracker["emitted_events"]), 2, "Unexpected number of emitted events.") self.assertIn(("StartEvent", "StartValue"), mock_tracker["emitted_events"], "Starting event not tracked.") self.assertIn(("EndEvent", "EndValue"), mock_tracker["emitted_events"], "Ending event not tracked.") + self.assertEqual(tracked_threads[0], tracked_threads[1], "Thread ID for start and end events differ.") @patch("samcli.lib.telemetry.event.EventTracker.send_events") @patch("samcli.lib.telemetry.event.EventTracker.track_event") From 677b1ab7ac3c5ae88433b875277880ec95e4893c Mon Sep 17 00:00:00 2001 From: Leonardo Gama Date: Tue, 16 May 2023 11:14:56 -0700 Subject: [PATCH 20/23] Reformat files to standard --- samcli/lib/sync/sync_flow_executor.py | 2 -- samcli/lib/telemetry/event.py | 14 +++++++++++--- 2 files changed, 11 insertions(+), 5 deletions(-) diff --git a/samcli/lib/sync/sync_flow_executor.py b/samcli/lib/sync/sync_flow_executor.py index 2c68ca2732..d6f712cfea 100644 --- a/samcli/lib/sync/sync_flow_executor.py +++ b/samcli/lib/sync/sync_flow_executor.py @@ -6,11 +6,9 @@ from queue import Queue from threading import RLock from typing import Callable, List, Optional, Set -from concurrent.futures import ThreadPoolExecutor, Future from uuid import uuid4 from botocore.exceptions import ClientError -from samcli.lib.telemetry.event import EventName, EventTracker, EventType from samcli.lib.providers.exceptions import MissingLocalDefinition from samcli.lib.sync.exceptions import ( diff --git a/samcli/lib/telemetry/event.py b/samcli/lib/telemetry/event.py index 4cc6301bca..2d819e37bf 100644 --- a/samcli/lib/telemetry/event.py +++ b/samcli/lib/telemetry/event.py @@ -88,7 +88,9 @@ class Event: time_stamp: str exception_name: Optional[str] - def __init__(self, event_name: str, event_value: str, thread_id: Optional[UUID] = None, exception_name: Optional[str] = None): + def __init__( + self, event_name: str, event_value: str, thread_id: Optional[UUID] = None, exception_name: Optional[str] = None + ): Event._verify_event(event_name, event_value) self.event_name = EventName(event_name) self.event_value = event_value @@ -148,7 +150,11 @@ class EventTracker: @staticmethod def track_event( - event_name: str, event_value: str, session_id: Optional[str] = None, thread_id: Optional[UUID] = None, exception_name: Optional[str] = None + event_name: str, + event_value: str, + session_id: Optional[str] = None, + thread_id: Optional[UUID] = None, + exception_name: Optional[str] = None, ): """Method to track an event where and when it occurs. @@ -192,7 +198,9 @@ def track_event( if not thread_id: # Passed value is not a UUID or None thread_id = uuid4() with EventTracker._event_lock: - EventTracker._events.append(Event(event_name, event_value, thread_id=thread_id, exception_name=exception_name)) + EventTracker._events.append( + Event(event_name, event_value, thread_id=thread_id, exception_name=exception_name) + ) # Get the session ID (needed for multithreading sending) EventTracker._set_session_id() From a84a9330e29d5b6624e9fbba00406f9f4891e583 Mon Sep 17 00:00:00 2001 From: Leonardo Gama Date: Tue, 16 May 2023 11:24:32 -0700 Subject: [PATCH 21/23] Clean up unnecessary files --- samcli/commands/build/build_context.py | 3 --- tests/unit/lib/telemetry/test_metric.py | 13 ------------- 2 files changed, 16 deletions(-) diff --git a/samcli/commands/build/build_context.py b/samcli/commands/build/build_context.py index 07dbf3f668..47d412511e 100644 --- a/samcli/commands/build/build_context.py +++ b/samcli/commands/build/build_context.py @@ -280,9 +280,6 @@ def run(self): self._handle_build_post_processing(builder, self._build_result) - for f in self.get_resources_to_build().functions: - EventTracker.track_event("BuildFunctionRuntime", f.runtime) - click.secho("\nBuild Succeeded", fg="green") # try to use relpath so the command is easier to understand, however, diff --git a/tests/unit/lib/telemetry/test_metric.py b/tests/unit/lib/telemetry/test_metric.py index 16f3b91b66..22f695eebe 100644 --- a/tests/unit/lib/telemetry/test_metric.py +++ b/tests/unit/lib/telemetry/test_metric.py @@ -3,7 +3,6 @@ from unittest import TestCase from unittest.mock import patch, Mock, ANY, call -from samcli.lib.telemetry.event import EventTracker import pytest import click @@ -395,18 +394,6 @@ def test_context_contains_exception(self, expected_exception, expected_code, sen send_events_mock.assert_called() - @patch("samcli.lib.telemetry.event.EventTracker.send_events", return_value=None) - @patch("samcli.lib.telemetry.metric.Context") - def test_must_send_events(self, ContextMock, send_mock): - ContextMock.get_current_context.return_value = self.context_mock - - def real_fn(): - pass - - track_command(real_fn)() - - send_mock.assert_called() - class TestParameterCapture(TestCase): def setUp(self): From 438adb8c6802b8befcbe3c0e5c4bdec473861b2c Mon Sep 17 00:00:00 2001 From: Leonardo Gama Date: Tue, 16 May 2023 12:50:16 -0700 Subject: [PATCH 22/23] Add thread ID tracking to infra sync executor --- samcli/lib/sync/infra_sync_executor.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/samcli/lib/sync/infra_sync_executor.py b/samcli/lib/sync/infra_sync_executor.py index 7b4a6ecde4..5a92d5777a 100644 --- a/samcli/lib/sync/infra_sync_executor.py +++ b/samcli/lib/sync/infra_sync_executor.py @@ -7,6 +7,7 @@ from datetime import datetime from pathlib import Path from typing import TYPE_CHECKING, Dict, Optional, Set +from uuid import uuid4 from boto3 import Session from botocore.exceptions import ClientError @@ -174,8 +175,9 @@ def execute_infra_sync(self, first_sync: bool = False) -> InfraSyncResult: days_since_last_infra_sync = (current_time - last_infra_sync_time).days # Will not combine the comparisons in order to save operation cost + thread_id = uuid4() if self._sync_context.skip_deploy_sync and first_sync and (days_since_last_infra_sync <= AUTO_INFRA_SYNC_DAYS): - EventTracker.track_event("SyncFlowStart", "SkipInfraSyncExecute") + EventTracker.track_event("SyncFlowStart", "SkipInfraSyncExecute", thread_id=thread_id) try: if self._auto_skip_infra_sync( self._package_context.output_template_file, @@ -199,7 +201,7 @@ def execute_infra_sync(self, first_sync: bool = False) -> InfraSyncResult: "Could not skip infra sync by comparing to a previously deployed template, starting infra sync" ) - EventTracker.track_event("SyncFlowStart", "InfraSyncExecute") + EventTracker.track_event("SyncFlowStart", "InfraSyncExecute", thread_id=thread_id) if days_since_last_infra_sync > AUTO_INFRA_SYNC_DAYS: LOG.info( "Infrastructure Sync hasn't been run in the last %s days, sam sync will be queuing up the stack" @@ -207,7 +209,7 @@ def execute_infra_sync(self, first_sync: bool = False) -> InfraSyncResult: AUTO_INFRA_SYNC_DAYS, ) self._deploy_context.run() - EventTracker.track_event("SyncFlowEnd", "InfraSyncExecute") + EventTracker.track_event("SyncFlowEnd", "InfraSyncExecute", thread_id=thread_id) # Update latest infra sync time in sync state self._sync_context.update_infra_sync_time() From dd0e54dca5168bb0e4301102502096ab65162e08 Mon Sep 17 00:00:00 2001 From: Leonardo Gama Date: Tue, 16 May 2023 13:58:09 -0700 Subject: [PATCH 23/23] Add missing thread ID to tracked event --- samcli/lib/sync/infra_sync_executor.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/samcli/lib/sync/infra_sync_executor.py b/samcli/lib/sync/infra_sync_executor.py index 5a92d5777a..257194a70a 100644 --- a/samcli/lib/sync/infra_sync_executor.py +++ b/samcli/lib/sync/infra_sync_executor.py @@ -188,7 +188,7 @@ def execute_infra_sync(self, first_sync: bool = False) -> InfraSyncResult: # If higher than the threshold, we perform infra sync to improve performance if len(self.code_sync_resources) < SYNC_FLOW_THRESHOLD: LOG.info("Template haven't been changed since last deployment, skipping infra sync...") - EventTracker.track_event("SyncFlowEnd", "SkipInfraSyncExecute") + EventTracker.track_event("SyncFlowEnd", "SkipInfraSyncExecute", thread_id=thread_id) return InfraSyncResult(False, self.code_sync_resources) else: LOG.info(