chore: add Cloud Build build retry in deploy helper (#1436)

Author: daniel-cit

helpers/foundation-deployer/gcp/gcp.go

@@ -15,15 +15,22 @@
 package gcp
 
 import (
+	"context"
+	"encoding/json"
 	"fmt"
+	"regexp"
 	"strings"
 	"time"
 
 	"github.com/GoogleCloudPlatform/cloud-foundation-toolkit/infra/blueprint-test/pkg/gcloud"
+	"github.com/GoogleCloudPlatform/cloud-foundation-toolkit/infra/blueprint-test/pkg/utils"
 	"github.com/mitchellh/go-testing-interface"
 	"github.com/tidwall/gjson"
 
 	"github.com/terraform-google-modules/terraform-example-foundation/test/integration/testutils"
+
+	"google.golang.org/api/cloudbuild/v1"
+	"google.golang.org/api/option"
 )
 
 const (
@@ -34,23 +41,78 @@ const (
 	StatusCancelled = "CANCELLED"
 )
 
+type RetryOp struct {
+	Type  string `json:"@type"`
+	Build Build  `json:"build"`
+}
+type Build struct {
+	ID         string `json:"id"`
+	Status     string `json:"status"`
+	CreateTime string `json:"createTime"`
+}
+
+var (
+	retryRegexp = map[*regexp.Regexp]string{}
+	// ctx         = context.Background()
+)
+
+func init() {
+	for e, m := range testutils.RetryableTransientErrors {
+		r, err := regexp.Compile(fmt.Sprintf("(?s)%s", e)) //(?s) enables dot (.) to match newline.
+		if err != nil {
+			panic(fmt.Sprintf("failed to compile regex %s: %s", e, err.Error()))
+		}
+		retryRegexp[r] = m
+	}
+}
+
 type GCP struct {
-	Runf      func(t testing.TB, cmd string, args ...interface{}) gjson.Result
-	sleepTime time.Duration
+	Runf            func(t testing.TB, cmd string, args ...interface{}) gjson.Result
+	RunCmd          func(t testing.TB, cmd string, args ...interface{}) string
+	TriggerNewBuild func(t testing.TB, ctx context.Context, buildName string) (string, error)
+	sleepTime       time.Duration
+}
+
+// runCmd is a wrapper around gcloud.RunCmd because the original function has an input with a private type
+func runCmd(t testing.TB, cmd string, args ...interface{}) string {
+	return gcloud.RunCmd(t, utils.StringFromTextAndArgs(append([]interface{}{cmd}, args...)...))
+}
+
+// triggerNewBuild triggers a new build based on the build provided
+func triggerNewBuild(t testing.TB, ctx context.Context, buildName string) (string, error) {
+
+	buildService, err := cloudbuild.NewService(ctx, option.WithScopes(cloudbuild.CloudPlatformScope))
+	if err != nil {
+		return "", fmt.Errorf("failed to create Cloud Build service: %w", err)
+	}
+	retryOperation, err := buildService.Projects.Locations.Builds.Retry(buildName, &cloudbuild.RetryBuildRequest{}).Do()
+	if err != nil {
+		return "", fmt.Errorf("failed to retry build: %w", err)
+	}
+
+	var data RetryOp
+	err = json.Unmarshal(retryOperation.Metadata, &data)
+	if err != nil {
+		return "", fmt.Errorf("error unmarshaling retry operation metadata: %v", err)
+	}
+
+	return data.Build.ID, nil
 }
 
 // NewGCP creates a new wrapper for Google Cloud Platform CLI.
 func NewGCP() GCP {
 	return GCP{
-		Runf:      gcloud.Runf,
-		sleepTime: 20,
+		Runf:            gcloud.Runf,
+		RunCmd:          runCmd,
+		TriggerNewBuild: triggerNewBuild,
+		sleepTime:       20,
 	}
 }
 
 // IsComponentInstalled checks if a given gcloud component is installed
 func (g GCP) IsComponentInstalled(t testing.TB, componentID string) bool {
-	filter := fmt.Sprintf("\"id='%s'\"",componentID)
-    components := g.Runf(t, "components list --filter %s", filter).Array()
+	filter := fmt.Sprintf("\"id='%s'\"", componentID)
+	components := g.Runf(t, "components list --filter %s", filter).Array()
 	if len(components) == 0 {
 		return false
 	}
@@ -70,8 +132,13 @@ func (g GCP) GetBuilds(t testing.TB, projectID, region, filter string) map[strin
 }
 
 // GetLastBuildStatus gets the status of the last build form a project and region that satisfy the given filter.
-func (g GCP) GetLastBuildStatus(t testing.TB, projectID, region, filter string) string {
-	return g.Runf(t, "builds list --project %s --region %s --limit 1 --sort-by ~createTime --filter %s", projectID, region, filter).Array()[0].Get("status").String()
+func (g GCP) GetLastBuildStatus(t testing.TB, projectID, region, filter string) (string, string) {
+	builds := g.Runf(t, "builds list --project %s --region %s --limit 1 --sort-by ~createTime --filter %s", projectID, region, filter).Array()
+	if len(builds) == 0 {
+		return "", ""
+	}
+	build := builds[0]
+	return build.Get("status").String(), build.Get("id").String()
 }
 
 // GetBuildStatus gets the status of the given build
@@ -91,16 +158,21 @@ func (g GCP) GetRunningBuildID(t testing.TB, projectID, region, filter string) s
 	return ""
 }
 
+// GetBuildLogs get the execution logs of the given build
+func (g GCP) GetBuildLogs(t testing.TB, projectID, region, buildID string) string {
+	return g.RunCmd(t, "builds log %s --project %s --region %s", buildID, projectID, region)
+}
+
 // GetFinalBuildState gets the terminal status of the given build. It will wait if build is not finished.
-func (g GCP) GetFinalBuildState(t testing.TB, projectID, region, buildID string, maxRetry int) (string, error) {
+func (g GCP) GetFinalBuildState(t testing.TB, projectID, region, buildID string, maxBuildRetry int) (string, error) {
 	var status string
 	count := 0
 	fmt.Printf("waiting for build %s execution.\n", buildID)
 	status = g.GetBuildStatus(t, projectID, region, buildID)
 	fmt.Printf("build status is %s\n", status)
 	for status != StatusSuccess && status != StatusFailure && status != StatusCancelled {
 		fmt.Printf("build status is %s\n", status)
-		if count >= maxRetry {
+		if count >= maxBuildRetry {
 			return "", fmt.Errorf("timeout waiting for build '%s' execution", buildID)
 		}
 		count = count + 1
@@ -112,29 +184,66 @@ func (g GCP) GetFinalBuildState(t testing.TB, projectID, region, buildID string,
 }
 
 // WaitBuildSuccess waits for the current build in a repo to finish.
-func (g GCP) WaitBuildSuccess(t testing.TB, project, region, repo, commitSha, failureMsg string, maxRetry int) error {
-	var filter string
+func (g GCP) WaitBuildSuccess(t testing.TB, project, region, repo, commitSha, failureMsg string, maxBuildRetry, maxErrorRetries int, timeBetweenErrorRetries time.Duration) error {
+	var filter, status, build string
+	var timeoutErr, err error
+	ctx := context.Background()
+
 	if commitSha == "" {
 		filter = fmt.Sprintf("source.repoSource.repoName:%s", repo)
 	} else {
 		filter = fmt.Sprintf("source.repoSource.commitSha:%s", commitSha)
 	}
-	build := g.GetRunningBuildID(t, project, region, filter)
-	if build != "" {
-		status, err := g.GetFinalBuildState(t, project, region, build, maxRetry)
-		if err != nil {
-			return err
+
+	build = g.GetRunningBuildID(t, project, region, filter)
+	for i := 0; i < maxErrorRetries; i++ {
+		if build != "" {
+			status, timeoutErr = g.GetFinalBuildState(t, project, region, build, maxBuildRetry)
+			if timeoutErr != nil {
+				return timeoutErr
+			}
+		} else {
+			status, build = g.GetLastBuildStatus(t, project, region, filter)
+			if build == "" {
+				return fmt.Errorf("no build found for filter: %s", filter)
+			}
 		}
+
 		if status != StatusSuccess {
-			return fmt.Errorf("%s\nSee:\nhttps://console.cloud.google.com/cloud-build/builds;region=%s/%s?project=%s\nfor details", failureMsg, region, build, project)
+			if !g.IsRetryableError(t, project, region, build) {
+				return fmt.Errorf("%s\nSee:\nhttps://console.cloud.google.com/cloud-build/builds;region=%s/%s?project=%s\nfor details", failureMsg, region, build, project)
+			}
+			fmt.Println("build failed with retryable error. a new build will be triggered.")
+		} else {
+			return nil // Build succeeded
 		}
-	} else {
-		status := g.GetLastBuildStatus(t, project, region, filter)
-		if status != StatusSuccess {
-			return fmt.Errorf("%s\nSee:\nhttps://console.cloud.google.com/cloud-build/builds;region=%s/%s?project=%s\nfor details", failureMsg, region, build, project)
+
+		// Trigger a new build
+		build, err = g.TriggerNewBuild(t, ctx, fmt.Sprintf("projects/%s/locations/%s/builds/%s", project, region, build))
+		if err != nil {
+			return fmt.Errorf("failed to trigger new build (attempt %d/%d): %w", i+1, maxErrorRetries, err)
+		}
+		fmt.Printf("triggered new build with ID: %s (attempt %d/%d)\n", build, i+1, maxErrorRetries)
+		if i < maxErrorRetries-1 {
+			time.Sleep(timeBetweenErrorRetries) // Wait before retrying
+		}
+	}
+	return fmt.Errorf("%s\nbuild failed after %d retries.\nSee Cloud Build logs for details", failureMsg, maxErrorRetries)
+}
+
+// IsRetryableError checks the logs of a failed Cloud Build build
+// and verify if the error is a transient one and can be retried
+func (g GCP) IsRetryableError(t testing.TB, projectID, region, build string) bool {
+	logs := g.GetBuildLogs(t, projectID, region, build)
+	found := false
+	for pattern, msg := range retryRegexp {
+		if pattern.MatchString(logs) {
+			found = true
+			fmt.Printf("error '%s' is worth of a retry\n", msg)
+			break
 		}
 	}
-	return nil
+	return found
 }
 
 // HasSccNotification checks if a Security Command Center notification exists
@@ -158,12 +267,12 @@ func (g GCP) HasTagKey(t testing.TB, orgID, tag string) bool {
 }
 
 // EnableApis enables the apis in the given project
-func (g GCP) EnableApis(t testing.TB, project string, apis []string) {
+func (g GCP) EnableAPIs(t testing.TB, project string, apis []string) {
 	g.Runf(t, "services enable %s --project %s", strings.Join(apis, " "), project)
 }
 
-// IsApiEnabled checks if the api is enabled in the given project
-func (g GCP) IsApiEnabled(t testing.TB, project, api string) bool {
+// IsAPIEnabled checks if the api is enabled in the given project
+func (g GCP) IsAPIEnabled(t testing.TB, project, api string) bool {
 	filter := fmt.Sprintf("config.name=%s", api)
 	return len(g.Runf(t, "services list --enabled --project %s --filter %s", project, filter).Array()) > 0
 }

helpers/foundation-deployer/gcp/gcp_test.go

@@ -15,13 +15,17 @@
 package gcp
 
 import (
+	"context"
 	"fmt"
 	"os"
 	"path/filepath"
+	"time"
+
 	gotest "testing"
 
 	"github.com/mitchellh/go-testing-interface"
 	"github.com/stretchr/testify/assert"
+
 	"github.com/tidwall/gjson"
 )
 
@@ -71,12 +75,12 @@ func TestGetLastBuildStatus(t *gotest.T) {
 		},
 		sleepTime: 1,
 	}
-	status := gcp.GetLastBuildStatus(t, "prj-b-cicd-0123", "us-central1", "filter")
+	status, _ := gcp.GetLastBuildStatus(t, "prj-b-cicd-0123", "us-central1", "filter")
 	assert.Equal(t, StatusSuccess, status)
 
 	current, err = os.ReadFile(filepath.Join(".", "testdata", "failure_build.json"))
 	assert.NoError(t, err)
-	status = gcp.GetLastBuildStatus(t, "prj-b-cicd-0123", "us-central1", "filter")
+	status, _ = gcp.GetLastBuildStatus(t, "prj-b-cicd-0123", "us-central1", "filter")
 	assert.Equal(t, StatusFailure, status)
 }
 
@@ -132,10 +136,13 @@ func TestWaitBuildSuccess(t *gotest.T) {
 			callCount = callCount + 1
 			return resp
 		},
+		RunCmd: func(t testing.TB, cmd string, args ...interface{}) string {
+			return ""
+		},
 		sleepTime: 1,
 	}
 
-	err = gcp.WaitBuildSuccess(t, "prj-b-cicd-0123", "us-central1", "repo", "", "failed_test_for_WaitBuildSuccess", 40)
+	err = gcp.WaitBuildSuccess(t, "prj-b-cicd-0123", "us-central1", "repo", "", "failed_test_for_WaitBuildSuccess", 40, 2, 1*time.Second)
 	assert.Error(t, err, "should have failed")
 	assert.Contains(t, err.Error(), "failed_test_for_WaitBuildSuccess", "should have failed with custom info")
 	assert.Equal(t, callCount, 3, "Runf must be called three times")
@@ -164,11 +171,66 @@ func TestWaitBuildTimeout(t *gotest.T) {
 			callCount = callCount + 1
 			return resp
 		},
+		RunCmd: func(t testing.TB, cmd string, args ...interface{}) string {
+			return ""
+		},
 		sleepTime: 1,
 	}
 
-	err = gcp.WaitBuildSuccess(t, "prj-b-cicd-0123", "us-central1", "repo", "", "failed_test_for_WaitBuildSuccess", 1)
+	err = gcp.WaitBuildSuccess(t, "prj-b-cicd-0123", "us-central1", "repo", "", "failed_test_for_WaitBuildSuccess", 1, 1, 1*time.Second)
 	assert.Error(t, err, "should have failed")
 	assert.Contains(t, err.Error(), "timeout waiting for build '736f4689-2497-4382-afd0-b5f0f50eea5b' execution", "should have failed with timeout error")
 	assert.Equal(t, callCount, 3, "Runf must be called three times")
 }
+
+func TestWaitBuildSuccessRetry(t *gotest.T) {
+
+	working, err := os.ReadFile(filepath.Join(".", "testdata", "working_build.json"))
+	assert.NoError(t, err)
+	failure, err := os.ReadFile(filepath.Join(".", "testdata", "failure_build.json"))
+	assert.NoError(t, err)
+	retry, err := os.ReadFile(filepath.Join(".", "testdata", "working_build_retry.json"))
+	assert.NoError(t, err)
+	success, err := os.ReadFile(filepath.Join(".", "testdata", "success_build.json"))
+	assert.NoError(t, err)
+
+	runCmdCallCount := 0
+	triggerNewBuildCallCount := 0
+	runfCallCount := 0
+	runfCalls := []gjson.Result{
+		{Type: gjson.JSON,
+			Raw: fmt.Sprintf("[%s]", string(working[:]))}, // builds list
+		{Type: gjson.JSON,
+			Raw: string(working[:])}, // builds describe
+		{Type: gjson.JSON,
+			Raw: string(failure[:])}, // builds describe
+		{Type: gjson.JSON,
+			Raw: string(retry[:])}, // builds describe
+		{Type: gjson.JSON,
+			Raw: string(success[:])}, // builds describe
+	}
+
+	gcp := GCP{
+		Runf: func(t testing.TB, cmd string, args ...interface{}) gjson.Result {
+			resp := runfCalls[runfCallCount]
+			runfCallCount = runfCallCount + 1
+			return resp
+		},
+		RunCmd: func(t testing.TB, cmd string, args ...interface{}) string {
+			runCmdCallCount = runCmdCallCount + 1
+			return "a\nError 403. Compute Engine API has not been used in project\nz" // get build logs
+		},
+		TriggerNewBuild: func(t testing.TB, ctx context.Context, buildName string) (string, error) {
+			triggerNewBuildCallCount = triggerNewBuildCallCount + 1
+			return "845f5790-2497-4382-afd0-b5f0f50eea5a", nil // buildService.Projects.Locations.Builds.Retry
+		},
+		sleepTime: 1,
+	}
+
+	err = gcp.WaitBuildSuccess(t, "prj-b-cicd-0123", "us-central1", "repo", "", "", 40, 2, 1*time.Second)
+
+	assert.Nil(t, err, "should have succeeded")
+	assert.Equal(t, runfCallCount, 5, "Runf must be called five times")
+	assert.Equal(t, runCmdCallCount, 1, "runCmd getLogs must be called once")
+	assert.Equal(t, triggerNewBuildCallCount, 1, "TriggerNewBuild must be called once")
+}