Fix infinite deploy loop on small stack edge case

samcli/commands/deploy/command.py

@@ -45,7 +45,7 @@
 HELP_TEXT = """The sam deploy command creates a Cloudformation Stack and deploys your resources.
 
 \b
-Set SAM_CLI_POLL_DELAY Environment Vairable with a value of seconds in your shell to configure 
+Set SAM_CLI_POLL_DELAY Environment Variable with a value of seconds in your shell to configure 
 how often SAM CLI checks the Stack state, which is useful when seeing throttling from CloudFormation.
 
 \b

samcli/commands/deploy/deploy_context.py

@@ -264,8 +264,8 @@ def deploy(
                     if not click.confirm(f"{self.MSG_CONFIRM_CHANGESET}", default=False):
                         return
 
-                self.deployer.execute_changeset(result["Id"], stack_name, disable_rollback)
-                self.deployer.wait_for_execute(stack_name, changeset_type, disable_rollback)
+                execution_time = self.deployer.execute_changeset(result["Id"], stack_name, disable_rollback)
+                self.deployer.wait_for_execute(stack_name, changeset_type, disable_rollback, execution_time)
                 click.echo(self.MSG_EXECUTE_SUCCESS.format(stack_name=stack_name, region=region))
 
             except deploy_exceptions.ChangeEmptyError as ex:

samcli/lib/deploy/deployer.py

@@ -327,19 +327,20 @@ def wait_for_changeset(self, changeset_id, stack_name):
                 stack_name=stack_name, msg="ex: {0} Status: {1}. Reason: {2}".format(ex, status, reason)
             ) from ex
 
-    def execute_changeset(self, changeset_id, stack_name, disable_rollback):
+    def execute_changeset(self, changeset_id, stack_name, disable_rollback) -> float:
         """
         Calls CloudFormation to execute changeset
 
         :param changeset_id: ID of the changeset
         :param stack_name: Name or ID of the stack
         :param disable_rollback: Preserve the state of previously provisioned resources when an operation fails.
-        :return: Response from execute-change-set call
+        :return: Changeset execution time (current time)
         """
         try:
-            return self._client.execute_change_set(
+            self._client.execute_change_set(
                 ChangeSetName=changeset_id, StackName=stack_name, DisableRollback=disable_rollback
             )
+            return time.time()
         except botocore.exceptions.ClientError as ex:
             raise DeployFailedError(stack_name=stack_name, msg=str(ex)) from ex
 
@@ -444,7 +445,9 @@ def _is_root_stack_event(event: Dict) -> bool:
     def _check_stack_not_in_progress(status: str) -> bool:
         return "IN_PROGRESS" not in status
 
-    def wait_for_execute(self, stack_name: str, stack_operation: str, disable_rollback: bool) -> None:
+    def wait_for_execute(
+        self, stack_name: str, stack_operation: str, disable_rollback: bool, execution_time: float = time.time()
+    ) -> None:
         """
         Wait for stack operation to execute and return when execution completes.
         If the stack has "Outputs," they will be printed.
@@ -457,14 +460,17 @@ def wait_for_execute(self, stack_name: str, stack_operation: str, disable_rollba
             The type of the stack operation, 'CREATE' or 'UPDATE'
         disable_rollback : bool
             Preserves the state of previously provisioned resources when an operation fails
+        execution_time : float
+            Time of the last stack change execution request (like `execute_change_set`, `update_stack`, `create_stack`)
+            Prevents missing events if the event streaming is delayed from the change request by any action in between
         """
         sys.stdout.write(
             "\n{} - Waiting for stack create/update "
             "to complete\n".format(datetime.now().strftime("%Y-%m-%d %H:%M:%S"))
         )
         sys.stdout.flush()
 
-        self.describe_stack_events(stack_name, self.get_last_event_time(stack_name))
+        self.describe_stack_events(stack_name, execution_time)
 
         # Pick the right waiter
         if stack_operation == "CREATE":
@@ -589,11 +595,11 @@ def sync(
 
             if exists:
                 result = self.update_stack(**kwargs)
-                self.wait_for_execute(stack_name, "UPDATE", False)
+                self.wait_for_execute(stack_name, "UPDATE", False, time.time())
                 msg = "\nStack update succeeded. Sync infra completed.\n"
             else:
                 result = self.create_stack(**kwargs)
-                self.wait_for_execute(stack_name, "CREATE", False)
+                self.wait_for_execute(stack_name, "CREATE", False, time.time())
                 msg = "\nStack creation succeeded. Sync infra completed.\n"
 
             LOG.info(self._colored.green(msg))

tests/unit/lib/deploy/test_deployer.py

@@ -355,11 +355,13 @@ def test_wait_for_changeset_exception_ChangeEmpty(self):
         with self.assertRaises(ChangeSetError):
             self.deployer.wait_for_changeset("test-id", "test-stack")
 
+    @patch("time.time", MagicMock(return_value=1656278830.0544872))
     def test_execute_changeset(self):
-        self.deployer.execute_changeset("id", "test", True)
+        execution_time = self.deployer.execute_changeset("id", "test", True)
         self.deployer._client.execute_change_set.assert_called_with(
             ChangeSetName="id", StackName="test", DisableRollback=True
         )
+        self.assertEquals(execution_time, 1656278830.0544872)
 
     def test_execute_changeset_exception(self):
         self.deployer._client.execute_change_set = MagicMock(
@@ -1007,10 +1009,10 @@ def test_check_stack_status(self):
     def test_wait_for_execute(self, patched_time):
         self.deployer.describe_stack_events = MagicMock()
         self.deployer._client.get_waiter = MagicMock(return_value=MockCreateUpdateWaiter())
-        self.deployer.wait_for_execute("test", "CREATE", False)
-        self.deployer.wait_for_execute("test", "UPDATE", True)
+        self.deployer.wait_for_execute("test", "CREATE", False, time.time())
+        self.deployer.wait_for_execute("test", "UPDATE", True, time.time())
         with self.assertRaises(RuntimeError):
-            self.deployer.wait_for_execute("test", "DESTRUCT", False)
+            self.deployer.wait_for_execute("test", "DESTRUCT", False, time.time())
 
         self.deployer._client.get_waiter = MagicMock(
             return_value=MockCreateUpdateWaiter(
@@ -1022,7 +1024,7 @@ def test_wait_for_execute(self, patched_time):
             )
         )
         with self.assertRaises(DeployFailedError):
-            self.deployer.wait_for_execute("test", "CREATE", False)
+            self.deployer.wait_for_execute("test", "CREATE", False, time.time())
 
     def test_create_and_wait_for_changeset(self):
         self.deployer.create_changeset = MagicMock(return_value=({"Id": "test"}, "create"))
@@ -1123,7 +1125,7 @@ def test_wait_for_execute_no_outputs(self, patched_time):
         self.deployer._client.get_waiter = MagicMock(return_value=MockCreateUpdateWaiter())
         self.deployer._display_stack_outputs = MagicMock()
         self.deployer.get_stack_outputs = MagicMock(return_value=None)
-        self.deployer.wait_for_execute("test", "CREATE", False)
+        self.deployer.wait_for_execute("test", "CREATE", False, time.time())
         self.assertEqual(self.deployer._display_stack_outputs.call_count, 0)
 
     @patch("time.sleep")
@@ -1142,7 +1144,7 @@ def test_wait_for_execute_with_outputs(self, patched_time):
         self.deployer._client.get_waiter = MagicMock(return_value=MockCreateUpdateWaiter())
         self.deployer._display_stack_outputs = MagicMock()
         self.deployer.get_stack_outputs = MagicMock(return_value=outputs["Stacks"][0]["Outputs"])
-        self.deployer.wait_for_execute("test", "CREATE", False)
+        self.deployer.wait_for_execute("test", "CREATE", False, time.time())
         self.assertEqual(self.deployer._display_stack_outputs.call_count, 1)
 
     def test_sync_update_stack(self):