Bug: deploy with large SAM_CLI_POLL_DELAY has a wrong display (nightly)

[BourgoisMickael]

Description:

Not a breaking bug, more like a display and timing bug

If we use the feature from my last PR #3500, using SAM_CLI_POLL_DELAY with a large delay like a minute, the events retrieved during the poll will be displayed in reverse order (because describe-stack-events is in reverse chronological order).

Also during the sleep, the deployment can end and another process could start another deploy so the stack will be IN_PROGRESS again and when the first sam deploy wakes up it misses the end of the first deployment and will keep running and catch the events of the second deployment.

Steps to reproduce:

Use sam-cli-nightly
SAM_CLI_POLL_DELAY=60 sam deploy ...

Check on cloudformation that the stack completes and while the first CLI is still running (sleeping)
Run sam deploy ... again in another tty.

Observed result:

Wrong order and display 2 deployments

-------------------------------------------------------------------------------------------------------------------------
ResourceStatus                 ResourceType                   LogicalResourceId              ResourceStatusReason
-------------------------------------------------------------------------------------------------------------------------
UPDATE_COMPLETE_CLEANUP_IN_P   AWS::CloudFormation::Stack     my-stack                       -
ROGRESS
UPDATE_COMPLETE                AWS::CloudFormation::Stack     AsyncLambdaApp                 -
UPDATE_IN_PROGRESS             AWS::CloudFormation::Stack     AsyncLambdaApp                 -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     DynamoApp                      -
UPDATE_IN_PROGRESS             AWS::CloudFormation::Stack     DynamoApp                      -
UPDATE_IN_PROGRESS             AWS::CloudFormation::Stack     AsyncLambdaApp                 -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     DynamoApp                      -
UPDATE_IN_PROGRESS             AWS::CloudFormation::Stack     DynamoApp                      -
UPDATE_IN_PROGRESS             AWS::CloudFormation::Stack     my-stack                       User Initiated
UPDATE_COMPLETE                AWS::CloudFormation::Stack     my-stack                       -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     DynamoApp                      -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     AsyncLambdaApp                 -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     my-stack                       -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     DynamoApp                      -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     AsyncLambdaApp                 -
UPDATE_COMPLETE_CLEANUP_IN_P   AWS::CloudFormation::Stack     my-stack                       -
ROGRESS
UPDATE_COMPLETE                AWS::CloudFormation::Stack     AsyncLambdaApp                 -
-------------------------------------------------------------------------------------------------------------------------

Expected result:

-------------------------------------------------------------------------------------------------------------------------
ResourceStatus                 ResourceType                   LogicalResourceId              ResourceStatusReason
-------------------------------------------------------------------------------------------------------------------------
UPDATE_IN_PROGRESS             AWS::CloudFormation::Stack     DynamoApp                      -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     DynamoApp                      -
UPDATE_IN_PROGRESS             AWS::CloudFormation::Stack     AsyncLambdaApp                 -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     AsyncLambdaApp                 -
UPDATE_COMPLETE_CLEANUP_IN_P   AWS::CloudFormation::Stack     my-stack                       -
ROGRESS
UPDATE_COMPLETE                AWS::CloudFormation::Stack     DynamoApp                      -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     AsyncLambdaApp                 -
UPDATE_COMPLETE                AWS::CloudFormation::Stack     my-stack                       -
-------------------------------------------------------------------------------------------------------------------------

Additional environment details (Ex: Windows, Mac, Amazon Linux etc)

[Unstable] Nightly Release v1.50.0.dev202205260901 - 2022-05-26

---

Solution

1: In describe_stack_events Instead of immediately print events, they should be buffered during pagination loop and reordered to print.

And in the reordered list find if the stack is not in progress to skip other deployments events (explained in #3911).
Maybe we could use EventId instead of Timestamp to have an exact comparison ?

2: Or maybe we could see with the cloudformation team if the DescribeStackEvents could be improved to pass the order and starting EventId or Timestamp and it does the ordering/filter for us.
(As the second solution might take some time, I'll go on the first one)

---

@jfuss @moelasmar @mndeveci What do you think about this ? I could work on a PR to get this and #3911 done quickly

[mingkun2020]

Thanks @BourgoisMickael for reporting the issue, we will be investigating it further and review your pr

[jfuss]

We only close issues on release. Reopen and updated labels.

[torresxb1]

Closing as #3919 was released with version 1.52.0
Thanks!