chore: Add debug info when an task fails to deploy

internal/pkg/aws/ecs/task.go

@@ -55,7 +55,7 @@ type Task ecs.Task
 // becomes "4082490e (sample-fargate:2)"
 func (t Task) String() string {
 	taskID, _ := TaskID(aws.StringValue(t.TaskArn))
-	taskID = shortTaskID(taskID)
+	taskID = ShortTaskID(taskID)
 	taskDefName, _ := taskDefinitionName(aws.StringValue(t.TaskDefinitionArn))
 	return fmt.Sprintf("%s (%s)", taskID, taskDefName)
 }
@@ -291,7 +291,9 @@ func TaskDefinitionVersion(taskDefARN string) (int, error) {
 	return version, nil
 }
 
-func shortTaskID(id string) string {
+// ShortTaskID truncates a string to a maximum length of shortTaskIDLength.
+// If the input is shorter, it remains unchanged.
+func ShortTaskID(id string) string {
 	if len(id) >= shortTaskIDLength {
 		return id[:shortTaskIDLength]
 	}

internal/pkg/aws/ecs/task_test.go

@@ -628,6 +628,35 @@ func TestTaskDefinition_EntryPoint(t *testing.T) {
 	}
 }
 
+func TestShortTaskID(t *testing.T) {
+	testCases := map[string]struct {
+		inTaskId     string
+		wantedTaskId string
+	}{
+		"return truncated short task id": {
+			inTaskId:     "37930fffc2104a1db455aef109b5d122",
+			wantedTaskId: "37930fff",
+		},
+		"return given short taskid": {
+			inTaskId:     "37930fff",
+			wantedTaskId: "37930fff",
+		},
+	}
+
+	for name, tc := range testCases {
+		t.Run(name, func(t *testing.T) {
+			// GIVEN
+			ctrl := gomock.NewController(t)
+			defer ctrl.Finish()
+			// WHEN
+			got := ShortTaskID(tc.inTaskId)
+			// THEN
+			require.Equal(t, tc.wantedTaskId, got)
+		})
+
+	}
+}
+
 func TestFilterRunningTasks(t *testing.T) {
 	testCases := map[string]struct {
 		inTasks     []*Task

internal/pkg/deploy/cloudformation/cloudformation_test.go

@@ -359,6 +359,7 @@ Resources:
 			},
 		},
 	}, nil)
+	mockECS.EXPECT().StoppedServiceTasks("cluster", "service").Return(nil, nil)
 	mockCFN.EXPECT().Describe(stackName).Return(&cloudformation.StackDescription{
 		StackStatus: aws.String("CREATE_COMPLETE"),
 	}, nil)

internal/pkg/stream/ecs.go

@@ -6,6 +6,7 @@ package stream
 import (
 	"fmt"
 	"math/rand"
+	"sort"
 	"strings"
 	"sync"
 	"time"
@@ -24,11 +25,16 @@ const (
 	rollOutEmpty               = ""
 )
 
+const (
+	ecsScalingActivity = "Scaling activity initiated by"
+)
+
 var ecsEventFailureKeywords = []string{"fail", "unhealthy", "error", "throttle", "unable", "missing", "alarm detected", "rolling back"}
 
 // ECSServiceDescriber is the interface to describe an ECS service.
 type ECSServiceDescriber interface {
 	Service(clusterName, serviceName string) (*ecs.Service, error)
+	StoppedServiceTasks(cluster, service string) ([]*ecs.Task, error)
 }
 
 // CloudWatchDescriber is the interface to describe CW alarms.
@@ -47,6 +53,7 @@ type ECSDeployment struct {
 	RolloutState    string
 	CreatedAt       time.Time
 	UpdatedAt       time.Time
+	Id              string
 }
 
 func (d ECSDeployment) isPrimary() bool {
@@ -69,6 +76,7 @@ type ECSService struct {
 	Deployments         []ECSDeployment
 	LatestFailureEvents []string
 	Alarms              []cloudwatch.AlarmStatus
+	StoppedTasks        []ecs.Task
 }
 
 // ECSDeploymentStreamer is a Streamer for ECSService descriptions until the deployment is completed.
@@ -135,6 +143,7 @@ func (s *ECSDeploymentStreamer) Fetch() (next time.Time, done bool, err error) {
 	s.ecsRetries = 0
 
 	var deployments []ECSDeployment
+	var primaryDeploymentId string
 	for _, deployment := range out.Deployments {
 		status := aws.StringValue(deployment.Status)
 		desiredCount, runningCount := aws.Int64Value(deployment.DesiredCount), aws.Int64Value(deployment.RunningCount)
@@ -148,12 +157,44 @@ func (s *ECSDeploymentStreamer) Fetch() (next time.Time, done bool, err error) {
 			RolloutState:    aws.StringValue(deployment.RolloutState),
 			CreatedAt:       aws.TimeValue(deployment.CreatedAt),
 			UpdatedAt:       aws.TimeValue(deployment.UpdatedAt),
+			Id:              aws.StringValue(deployment.Id),
 		}
 		deployments = append(deployments, rollingDeploy)
 		if isDeploymentDone(rollingDeploy, s.deploymentCreationTime) {
 			done = true
 		}
+		if rollingDeploy.isPrimary() {
+			primaryDeploymentId = rollingDeploy.Id
+		}
+	}
+	stoppedSvcTasks, err := s.client.StoppedServiceTasks(s.cluster, s.service)
+	if err != nil {
+		if request.IsErrorThrottle(err) {
+			s.ecsRetries += 1
+			return nextFetchDate(s.clock, s.rand, s.ecsRetries), false, nil
+		}
+		return next, false, fmt.Errorf("fetch stopped tasks: %w", err)
+	}
+	s.ecsRetries = 0
+
+	var stoppedTasks []ecs.Task
+	for _, st := range stoppedSvcTasks {
+		if stoppingAt := aws.TimeValue(st.StoppingAt); aws.StringValue(st.StartedBy) != primaryDeploymentId || stoppingAt.Before(s.deploymentCreationTime) ||
+			(strings.Contains(aws.StringValue(st.StoppedReason), ecsScalingActivity)) {
+			continue
+		}
+		stoppedTasks = append(stoppedTasks, ecs.Task{
+			TaskArn:       st.TaskArn,
+			DesiredStatus: st.DesiredStatus,
+			LastStatus:    st.LastStatus,
+			StoppedReason: st.StoppedReason,
+			StoppingAt:    st.StoppingAt,
+		})
 	}
+	sort.SliceStable(stoppedTasks, func(i, j int) bool {
+		return aws.TimeValue(stoppedTasks[i].StoppingAt).After(aws.TimeValue(stoppedTasks[j].StoppingAt))
+	})
+
 	var failureMsgs []string
 	for _, event := range out.Events {
 		if createdAt := aws.TimeValue(event.CreatedAt); createdAt.Before(s.deploymentCreationTime) {
@@ -187,6 +228,7 @@ func (s *ECSDeploymentStreamer) Fetch() (next time.Time, done bool, err error) {
 		Deployments:         deployments,
 		LatestFailureEvents: failureMsgs,
 		Alarms:              alarms,
+		StoppedTasks:        stoppedTasks,
 	})
 	return nextFetchDate(s.clock, s.rand, 0), done, nil
 }

internal/pkg/stream/ecs_test.go

@@ -5,19 +5,22 @@ package stream
 
 import (
 	"errors"
-	"github.com/aws/copilot-cli/internal/pkg/aws/cloudwatch"
 	"testing"
 	"time"
 
+	"github.com/aws/copilot-cli/internal/pkg/aws/cloudwatch"
+
 	"github.com/aws/aws-sdk-go/aws"
 	awsecs "github.com/aws/aws-sdk-go/service/ecs"
 	"github.com/aws/copilot-cli/internal/pkg/aws/ecs"
 	"github.com/stretchr/testify/require"
 )
 
 type mockECS struct {
-	out *ecs.Service
-	err error
+	out       *ecs.Service
+	tasks     []*ecs.Task
+	err       error
+	taskError error
 }
 
 type mockCW struct {
@@ -28,6 +31,9 @@ type mockCW struct {
 func (m mockECS) Service(clusterName, serviceName string) (*ecs.Service, error) {
 	return m.out, m.err
 }
+func (m mockECS) StoppedServiceTasks(clusterName, serviceName string) ([]*ecs.Task, error) {
+	return m.tasks, m.taskError
+}
 
 func (m mockCW) AlarmStatuses(opts ...cloudwatch.DescribeAlarmOpts) ([]cloudwatch.AlarmStatus, error) {
 	return m.out, m.err
@@ -97,6 +103,37 @@ func TestECSDeploymentStreamer_Fetch(t *testing.T) {
 		// THEN
 		require.EqualError(t, err, "retrieve alarm statuses: some error")
 	})
+	t.Run("returns a wrapped error on stopped tasks call failure", func(t *testing.T) {
+		// GIVEN
+		m := mockECS{
+			out: &ecs.Service{
+				DeploymentConfiguration: &awsecs.DeploymentConfiguration{
+					Alarms: &awsecs.DeploymentAlarms{
+						AlarmNames: []*string{aws.String("alarm1"), aws.String("alarm2")},
+						Enable:     aws.Bool(true),
+						Rollback:   aws.Bool(true),
+					},
+				},
+			},
+			tasks: []*ecs.Task{
+				{
+					TaskArn:       aws.String("arn:aws:ecs:us-east-2:197732814171:task/testbugbash-testenv-Cluster-qrvEB"),
+					DesiredStatus: aws.String("Stopped"),
+					LastStatus:    aws.String("Deprovisioning"),
+					StoppedReason: aws.String("unable to pull secrets"),
+				},
+			},
+			taskError: errors.New("some error"),
+		}
+		cw := mockCW{}
+		streamer := NewECSDeploymentStreamer(m, cw, "my-cluster", "my-svc", time.Now())
+
+		// WHEN
+		_, _, err := streamer.Fetch()
+
+		// THEN
+		require.EqualError(t, err, "fetch stopped tasks: some error")
+	})
 	t.Run("stores events, alarms, and failures until deployment is done", func(t *testing.T) {
 		// GIVEN
 		oldStartDate := time.Date(2020, time.November, 23, 17, 0, 0, 0, time.UTC)
@@ -113,6 +150,7 @@ func TestECSDeploymentStreamer_Fetch(t *testing.T) {
 						Status:         aws.String("PRIMARY"),
 						TaskDefinition: aws.String("arn:aws:ecs:us-west-2:1111:task-definition/myapp-test-mysvc:2"),
 						UpdatedAt:      aws.Time(startDate),
+						Id:             aws.String("ecs-svc/123"),
 					},
 					{
 						DesiredCount:   aws.Int64(10),
@@ -123,6 +161,7 @@ func TestECSDeploymentStreamer_Fetch(t *testing.T) {
 						Status:         aws.String("ACTIVE"),
 						TaskDefinition: aws.String("arn:aws:ecs:us-west-2:1111:task-definition/myapp-test-mysvc:1"),
 						UpdatedAt:      aws.Time(oldStartDate),
+						Id:             aws.String("ecs-svc/456"),
 					},
 				},
 				DeploymentConfiguration: &awsecs.DeploymentConfiguration{
@@ -145,6 +184,40 @@ func TestECSDeploymentStreamer_Fetch(t *testing.T) {
 					},
 				},
 			},
+			tasks: []*ecs.Task{
+				{
+					TaskArn:       aws.String("arn:aws:ecs:us-east-2:197732814171:task/bugbash-test-Cluster-qrvEB"),
+					DesiredStatus: aws.String("Stopped"),
+					LastStatus:    aws.String("Deprovisioning"),
+					StoppedReason: aws.String("unable to pull secrets"),
+					StoppingAt:    aws.Time(startDate.Add(10 * time.Second)),
+					StartedBy:     aws.String("ecs-svc/123"),
+				},
+				{
+					TaskArn:       aws.String("arn:aws:ecs:us-east-2:197732814171:task/bugbash-test-Cluster-qrvEBt"),
+					DesiredStatus: aws.String("Stopped"),
+					LastStatus:    aws.String("Stopped"),
+					StoppedReason: aws.String("unable to pull secrets"),
+					StoppingAt:    aws.Time(oldStartDate),
+					StartedBy:     aws.String("ecs-svc/123"),
+				},
+				{
+					TaskArn:       aws.String("arn:aws:ecs:us-east-2:197732814171:task/bugbash-test-Cluster-qrvEBs"),
+					DesiredStatus: aws.String("Stopped"),
+					LastStatus:    aws.String("Deprovisioning"),
+					StoppedReason: aws.String("ELB healthcheck failed"),
+					StoppingAt:    aws.Time(startDate.Add(20 * time.Second)),
+					StartedBy:     aws.String("ecs-svc/123"),
+				},
+				{
+					TaskArn:       aws.String("arn:aws:ecs:us-east-2:197732814171:task/bugbash-test-Cluster-qrvEBu"),
+					DesiredStatus: aws.String("Stopped"),
+					LastStatus:    aws.String("Deprovisioning"),
+					StoppedReason: aws.String("Scaling activity initiated by deployment ecs-svc/mocktaskid"),
+					StoppingAt:    aws.Time(startDate.Add(30 * time.Second)),
+					StartedBy:     aws.String("ecs-svc/123"),
+				},
+			},
 		}
 		cw := mockCW{
 			out: []cloudwatch.AlarmStatus{
@@ -177,6 +250,7 @@ func TestECSDeploymentStreamer_Fetch(t *testing.T) {
 						PendingCount:    0,
 						RolloutState:    "COMPLETED",
 						UpdatedAt:       startDate,
+						Id:              "ecs-svc/123",
 					},
 					{
 						Status:          "ACTIVE",
@@ -187,6 +261,7 @@ func TestECSDeploymentStreamer_Fetch(t *testing.T) {
 						PendingCount:    0,
 						RolloutState:    "FAILED",
 						UpdatedAt:       oldStartDate,
+						Id:              "ecs-svc/456",
 					},
 				},
 				Alarms: []cloudwatch.AlarmStatus{
@@ -200,6 +275,22 @@ func TestECSDeploymentStreamer_Fetch(t *testing.T) {
 					},
 				},
 				LatestFailureEvents: []string{"deployment failed: alarm detected", "rolling back to deployment X"},
+				StoppedTasks: []ecs.Task{
+					{
+						TaskArn:       aws.String("arn:aws:ecs:us-east-2:197732814171:task/bugbash-test-Cluster-qrvEBs"),
+						DesiredStatus: aws.String("Stopped"),
+						LastStatus:    aws.String("Deprovisioning"),
+						StoppedReason: aws.String("ELB healthcheck failed"),
+						StoppingAt:    aws.Time(startDate.Add(20 * time.Second)),
+					},
+					{
+						TaskArn:       aws.String("arn:aws:ecs:us-east-2:197732814171:task/bugbash-test-Cluster-qrvEB"),
+						DesiredStatus: aws.String("Stopped"),
+						LastStatus:    aws.String("Deprovisioning"),
+						StoppedReason: aws.String("unable to pull secrets"),
+						StoppingAt:    aws.Time(startDate.Add(10 * time.Second)),
+					},
+				},
 			},
 		}, streamer.eventsToFlush)
 		require.True(t, done, "there should be no more work to do since the deployment is completed")