Repository: bazelbuild/bazelisk (go)

Issue:
Add HTTP request retries where they make sense
Just noticed this error in one of our CI logs:

> 2021/07/13 04:26:30 could not resolve the version 'latest' to an actual version number: unable to determine latest version: could not list available releases for 4.1.0: could not list GCS objects at https://www.googleapis.com/storage/v1/b/bazel/o?delimiter=/&prefix=4.1.0/release/: unexpected status code while reading https://www.googleapis.com/storage/v1/b/bazel/o?delimiter=/&prefix=4.1.0/release/: 503

Looks like GCS responded with HTTP 503 Service Unavailable, which suggests that the request should be retried: "Common causes are a server that is down for maintenance or that is overloaded. This response should be used for temporary conditions and the Retry-After HTTP header should, if possible, contain the estimated time for the recovery of the service." (https://developer.mozilla.org/en-US/docs/Web/HTTP/Status/503)


Pull request:
Add HTTP retry mechanism
Bazelisk now retries failing HTTP requests whose status code indicates that a retry makes sense (e.g. 429, 503).
It considers a variety of HTTP headers (such as Retry-After, X-RateLimit-Reset, Rate-Limit-Reset) in order to determine when to retry.
If no such header is present Bazelisk employs an exponential backoff retry strategy (with some randomness).

Fixes #254

Patch:
diff --git a/BUILD b/BUILD
index ea6dba2..7254d33 100644
--- a/BUILD
+++ b/BUILD
@@ -51,9 +51,7 @@ go_library(
 
 go_test(
     name = "go_default_test",
-    srcs = [
-        "bazelisk_version_test.go",
-    ],
+    srcs = ["bazelisk_version_test.go"],
     data = [
         "sample-issues-migration.json",
     ],
@@ -63,7 +61,6 @@ go_test(
         "//core:go_default_library",
         "//httputil:go_default_library",
         "//repositories:go_default_library",
-        "//runfiles:go_default_library",
         "//versions:go_default_library",
     ],
 )
diff --git a/WORKSPACE b/WORKSPACE
index 334b506..49c72bf 100644
--- a/WORKSPACE
+++ b/WORKSPACE
@@ -60,11 +60,12 @@ load("@build_bazel_rules_nodejs//:index.bzl", "node_repositories")
 node_repositories()
 
 load("@bazel_tools//tools/build_defs/repo:http.bzl", "http_archive")
+
 http_archive(
     name = "platforms",
+    sha256 = "079945598e4b6cc075846f7fd6a9d0857c33a7afc0de868c2ccb96405225135d",
     urls = [
         "https://mirror.bazel.build/github.com/bazelbuild/platforms/releases/download/0.0.4/platforms-0.0.4.tar.gz",
         "https://github.com/bazelbuild/platforms/releases/download/0.0.4/platforms-0.0.4.tar.gz",
     ],
-    sha256 = "079945598e4b6cc075846f7fd6a9d0857c33a7afc0de868c2ccb96405225135d",
 )
diff --git a/httputil/BUILD b/httputil/BUILD
index 7374867..44049d0 100644
--- a/httputil/BUILD
+++ b/httputil/BUILD
@@ -1,8 +1,21 @@
-load("@io_bazel_rules_go//go:def.bzl", "go_library")
+load("@bazel_gazelle//:def.bzl", "gazelle")
+load("@io_bazel_rules_go//go:def.bzl", "go_library", "go_test")
+
+# gazelle:prefix github.com/bazelbuild/bazelisk/httputil
+gazelle(name = "gazelle")
 
 go_library(
     name = "go_default_library",
-    srcs = ["httputil.go"],
+    srcs = [
+        "fake.go",
+        "httputil.go",
+    ],
     importpath = "github.com/bazelbuild/bazelisk/httputil",
     visibility = ["//visibility:public"],
 )
+
+go_test(
+    name = "go_default_test",
+    srcs = ["httputil_test.go"],
+    embed = [":go_default_library"],
+)
diff --git a/httputil/fake.go b/httputil/fake.go
new file mode 100644
index 0000000..c674104
--- /dev/null
+++ b/httputil/fake.go
@@ -0,0 +1,69 @@
+package httputil
+
+import (
+	"bytes"
+	"io/ioutil"
+	"net/http"
+)
+
+type FakeTransport struct {
+	responses map[string]*responseCollection
+}
+
+func NewFakeTransport() *FakeTransport {
+	return &FakeTransport{
+		responses: make(map[string]*responseCollection),
+	}
+}
+
+func (ft *FakeTransport) AddResponse(url string, status int, body string, headers map[string]string) {
+	if _, ok := ft.responses[url]; !ok {
+		ft.responses[url] = &responseCollection{}
+	}
+
+	ft.responses[url].Add(createResponse(status, body, headers))
+}
+
+func (ft *FakeTransport) RoundTrip(req *http.Request) (*http.Response, error) {
+	if responses, ok := ft.responses[req.URL.String()]; ok {
+		return responses.Next(), nil
+	}
+	return notFound(), nil
+}
+
+type responseCollection struct {
+	all  []*http.Response
+	next int
+}
+
+func (rc *responseCollection) Add(resp *http.Response) {
+	rc.all = append(rc.all, resp)
+}
+
+func (rc *responseCollection) Next() *http.Response {
+	if rc.next >= len(rc.all) {
+		return notFound()
+	}
+	rc.next++
+	return rc.all[rc.next-1]
+}
+
+func createResponse(status int, body string, headers map[string]string) *http.Response {
+	return &http.Response{
+		StatusCode: status,
+		Body:       ioutil.NopCloser(bytes.NewBufferString(body)),
+		Header:     transformHeaders(headers),
+	}
+}
+
+func transformHeaders(original map[string]string) http.Header {
+	result := make(map[string][]string)
+	for k, v := range original {
+		result[k] = []string{v}
+	}
+	return result
+}
+
+func notFound() *http.Response {
+	return createResponse(http.StatusNotFound, "", nil)
+}
diff --git a/httputil/httputil.go b/httputil/httputil.go
index 1035a20..9afe1db 100644
--- a/httputil/httputil.go
+++ b/httputil/httputil.go
@@ -6,10 +6,12 @@ import (
 	"io"
 	"io/ioutil"
 	"log"
+	"math/rand"
 	"net/http"
 	"os"
 	"path/filepath"
 	"regexp"
+	"strconv"
 	"time"
 )
 
@@ -18,9 +20,33 @@ var (
 	DefaultTransport = http.DefaultTransport
 	UserAgent = "Bazelisk"
 	linkPattern = regexp.MustCompile(`<(.*?)>; rel="(\w+)"`)
+
+	RetryClock = Clock(&realClock{})
+	MaxRetries = 4
+	// MaxRequestDuration defines the maximum amount of time that a request and its retries may take in total
+	MaxRequestDuration = time.Second * 10
+	retryHeaders = []string{"Retry-After", "X-RateLimit-Reset", "Rate-Limit-Reset"}
 )
 
+type Clock interface {
+	Sleep(time.Duration)
+	Now() time.Time
+}
+
+type realClock struct {}
+
+func (*realClock) Sleep(d time.Duration) {
+	time.Sleep(d)
+}
+
+func (*realClock) Now() time.Time {
+	return time.Now()
+}
+
 // ReadRemoteFile returns the contents of the given file, using the supplied Authorization token, if set. It also returns the HTTP headers.
+// If the request fails with a transient error it will retry the request for at most MaxRetries times.
+// It obeys HTTP headers such as "Retry-After" when calculating the start time of the next attempt.
+// If no such header is present, it uses an exponential backoff strategy.
 func ReadRemoteFile(url string, token string) ([]byte, http.Header, error) {
 	res, err := get(url, token)
 	if err != nil {
@@ -50,7 +76,57 @@ func get(url, token string) (*http.Response, error) {
 		req.Header.Set("Authorization", "token "+token)
 	}
 	client := &http.Client{Transport: DefaultTransport}
-	return client.Do(req)
+	deadline := RetryClock.Now().Add(MaxRequestDuration)
+	lastStatus := 0
+	for attempt := 0; attempt <= MaxRetries; attempt++ {
+		res, err := client.Do(req)
+		// Do not retry on success and permanent/fatal errors
+		if err != nil || !shouldRetry(res) {
+			return res, err
+		}
+
+		lastStatus = res.StatusCode
+		waitFor, err := getWaitPeriod(res, attempt)
+		if err != nil {
+			return nil, err
+		}
+
+		nextTryAt := RetryClock.Now().Add(waitFor)
+		if nextTryAt.After(deadline) {
+			return nil, fmt.Errorf("unable to complete request to %s within %v", url, MaxRequestDuration)
+		}
+		if attempt < MaxRetries {
+			RetryClock.Sleep(waitFor)
+		}
+	}
+	return nil, fmt.Errorf("unable to complete request to %s after %d retries. Most recent status: %d", url, MaxRetries, lastStatus)
+}
+
+func shouldRetry(res *http.Response) bool {
+	return res.StatusCode == 429 || (500 <= res.StatusCode && res.StatusCode <= 504)
+}
+
+func getWaitPeriod(res *http.Response, attempt int) (time.Duration, error) {
+	// Check if the server told us when to retry
+	for _, header := range retryHeaders {
+		if value := res.Header[header]; len(value) > 0 {
+			return parseRetryHeader(value[0])
+		}
+	}
+	// Let's just use exponential backoff: 1s + d1, 2s + d2, 4s + d3, 8s + d4 with dx being a random value in [0ms, 500ms]
+	return time.Duration(1 << attempt) * time.Second + time.Duration(rand.Intn(500)) * time.Millisecond, nil
+}
+
+func parseRetryHeader(value string) (time.Duration, error) {
+	// Depending on the server the header value can be a number of seconds (how long to wait) or an actual date (when to retry).
+	if seconds, err := strconv.Atoi(value); err == nil {
+		return time.Second * time.Duration(seconds), nil
+	}
+	t, err := http.ParseTime(value)
+	if err != nil {
+		return 0, err
+	}
+	return time.Until(t), nil
 }
 
 // DownloadBinary downloads a file from the given URL into the specified location, marks it executable and returns its full path.


Test patch:
diff --git a/bazelisk_version_test.go b/bazelisk_version_test.go
index 878f62f..0de0f62 100644
--- a/bazelisk_version_test.go
+++ b/bazelisk_version_test.go
@@ -1,12 +1,10 @@
 package main
 
 import (
-	"bytes"
 	"encoding/json"
 	"fmt"
 	"io/ioutil"
 	"log"
-	"net/http"
 	"os"
 	"strings"
 	"testing"
@@ -140,7 +138,7 @@ func TestResolveLatestVersion_ShouldFailIfNotEnoughReleases(t *testing.T) {
 
 func TestResolveLatestVersion_GCSIsDown(t *testing.T) {
 	g := setUp(t).WithError().Finish()
-	g.Transport.AddResponse("https://www.googleapis.com/storage/v1/b/bazel/o?delimiter=/", 500, "")
+	g.Transport.AddResponse("https://www.googleapis.com/storage/v1/b/bazel/o?delimiter=/", 500, "", nil)
 
 	gcs := &repositories.GCSRepo{}
 	repos := core.CreateRepositories(gcs, nil, nil, nil, nil, false)
@@ -157,7 +155,7 @@ func TestResolveLatestVersion_GCSIsDown(t *testing.T) {
 
 func TestResolveLatestVersion_GitHubIsDown(t *testing.T) {
 	transport := installTransport()
-	transport.AddResponse("https://api.github.com/repos/bazelbuild/bazel/releases", 500, "")
+	transport.AddResponse("https://api.github.com/repos/bazelbuild/bazel/releases", 500, "", nil)
 
 	gh := repositories.CreateGitHubRepo("test_token")
 	repos := core.CreateRepositories(nil, nil, gh, nil, nil, false)
@@ -212,7 +210,7 @@ func TestResolveLatestRollingRelease(t *testing.T) {
 	]
 	`
 	transport := installTransport()
-	transport.AddResponse("https://api.github.com/repos/bazelbuild/bazel/releases", 200, text)
+	transport.AddResponse("https://api.github.com/repos/bazelbuild/bazel/releases", 200, text, nil)
 
 	gh := repositories.CreateGitHubRepo("test_token")
 	repos := core.CreateRepositories(nil, nil, nil, nil, gh, false)
@@ -234,7 +232,7 @@ type gcsSetup struct {
 	versionPrefixes []string
 	status          int
 	test            *testing.T
-	Transport       *fakeTransport
+	Transport       *httputil.FakeTransport
 }
 
 func (g *gcsSetup) AddVersion(version string, hasRelease bool, rcs []int, rolling []string) *gcsSetup {
@@ -272,7 +270,7 @@ func (g *gcsSetup) addURL(prefix string, containsItem bool, childPrefixes ...str
 		items = append(items, "this_is_a_release")
 	}
 	resp := buildGCSResponseOrFail(g.test, childPrefixes, items)
-	g.Transport.AddResponse(fmt.Sprintf("%s&prefix=%s", g.baseURL, prefix), 200, resp)
+	g.Transport.AddResponse(fmt.Sprintf("%s&prefix=%s", g.baseURL, prefix), 200, resp, nil)
 }
 
 func setUp(t *testing.T) *gcsSetup {
@@ -285,8 +283,8 @@ func setUp(t *testing.T) *gcsSetup {
 	}
 }
 
-func installTransport() *fakeTransport {
-	ft := &fakeTransport{responses: make(map[string]*http.Response)}
+func installTransport() *httputil.FakeTransport {
+	ft := httputil.NewFakeTransport()
 	httputil.DefaultTransport = ft
 	return ft
 }
@@ -299,32 +297,10 @@ func (g *gcsSetup) WithError() *gcsSetup {
 func (g *gcsSetup) Finish() *gcsSetup {
 	// TODO: sort and deduplicate versionPrefixes
 	listBody := buildGCSResponseOrFail(g.test, g.versionPrefixes, []interface{}{})
-	g.Transport.AddResponse(g.baseURL, g.status, listBody)
+	g.Transport.AddResponse(g.baseURL, g.status, listBody, nil)
 	return g
 }
 
-type fakeTransport struct {
-	responses map[string]*http.Response
-}
-
-func (ft *fakeTransport) AddResponse(url string, status int, body string) {
-	ft.responses[url] = ft.createResponse(status, body)
-}
-
-func (ft *fakeTransport) createResponse(status int, body string) *http.Response {
-	return &http.Response{
-		StatusCode: status,
-		Body:       ioutil.NopCloser(bytes.NewBufferString(body)),
-	}
-}
-
-func (ft *fakeTransport) RoundTrip(req *http.Request) (*http.Response, error) {
-	if resp, ok := ft.responses[req.URL.String()]; ok {
-		return resp, nil
-	}
-	return ft.createResponse(http.StatusNotFound, ""), nil
-}
-
 func buildGCSResponseOrFail(t *testing.T, prefixes []string, items []interface{}) string {
 	r := &repositories.GcsListResponse{
 		Prefixes: prefixes,
diff --git a/httputil/httputil_test.go b/httputil/httputil_test.go
new file mode 100644
index 0000000..97b7284
--- /dev/null
+++ b/httputil/httputil_test.go
@@ -0,0 +1,224 @@
+package httputil
+
+import (
+	"net/http"
+	"strconv"
+	"testing"
+	"time"
+)
+
+var (
+	seed = time.Now()
+)
+
+type fakeClock struct {
+	now          time.Time
+	SleepPeriods []time.Duration
+}
+
+func newFakeClock() *fakeClock {
+	return &fakeClock{now: seed}
+}
+
+func (fc *fakeClock) Sleep(d time.Duration) {
+	fc.now = fc.now.Add(d)
+	fc.SleepPeriods = append(fc.SleepPeriods, d)
+}
+
+func (fc *fakeClock) Now() time.Time {
+	return fc.now
+}
+
+func (fc *fakeClock) TimesSlept() int {
+	return len(fc.SleepPeriods)
+}
+
+func setUp() (*FakeTransport, *fakeClock) {
+	transport := NewFakeTransport()
+	DefaultTransport = transport
+
+	clock := newFakeClock()
+	RetryClock = clock
+	return transport, clock
+}
+
+func setUpAllFailures(url string, status, retries int, headers map[string]string) (*FakeTransport, *fakeClock) {
+	MaxRetries = retries
+
+	transport, clock := setUp()
+	for i := 0; i <= retries; i++ {
+		transport.AddResponse(url, status, "", headers)
+	}
+	return transport, clock
+}
+
+func TestSuccessOnFirstTry(t *testing.T) {
+	transport, _ := setUp()
+
+	url := "http://foo"
+	want := "the_body"
+	transport.AddResponse(url, 200, want, nil)
+	body, _, err := ReadRemoteFile(url, "")
+
+	if err != nil {
+		t.Fatalf("Unexpected error %v", err)
+	}
+
+	got := string(body)
+	if got != want {
+		t.Fatalf("Expected body %q, but got %q", want, got)
+	}
+}
+
+func TestSuccessOnRetry(t *testing.T) {
+	transport, clock := setUp()
+
+	url := "http://foo"
+	want := "the_body"
+	transport.AddResponse(url, 503, "", nil)
+	transport.AddResponse(url, 200, want, nil)
+	body, _, err := ReadRemoteFile(url, "")
+
+	if err != nil {
+		t.Fatalf("Unexpected error %v", err)
+	}
+
+	got := string(body)
+	if got != want {
+		t.Fatalf("Expected body %q, but got %q", want, got)
+	}
+
+	if clock.TimesSlept() != 1 {
+		t.Fatalf("Expected a single retry, not %d", clock.TimesSlept())
+	}
+}
+
+func TestAllTriesFail(t *testing.T) {
+	MaxRequestDuration = 100 * time.Second
+
+	url := "http://bar"
+	retries := 5
+	_, clock := setUpAllFailures(url, 502, retries, nil)
+
+	_, _, err := ReadRemoteFile(url, "")
+	if err == nil {
+		t.Fatal("Expected request to fail with code 502")
+	}
+
+	reason := err.Error()
+	expected := "could not fetch http://bar: unable to complete request to http://bar after 5 retries. Most recent status: 502"
+	if reason != expected {
+		t.Fatalf("Expected request to fail with %q, but got %q", expected, reason)
+	}
+
+	if clock.TimesSlept() != retries {
+		t.Fatalf("Expected %d retries, but got %d", retries, clock.TimesSlept())
+	}
+}
+
+func TestShouldObeyRetryHeaders(t *testing.T) {
+	MaxRequestDuration = time.Hour * 24
+
+	headerGens := []func(time.Duration) string{
+		func(d time.Duration) string {
+			// Value == earliest date to retry
+			return seed.Add(d).UTC().Format(http.TimeFormat)
+		},
+		func(d time.Duration) string {
+			// Value == seconds to wait
+			return strconv.Itoa(int(d.Seconds()))
+		},
+	}
+
+	for _, header := range retryHeaders {
+		for _, gen := range headerGens {
+			url := "http://bar"
+			wanted := 5 * time.Hour
+			_, clock := setUpAllFailures(url, 501, 1, map[string]string{header: gen(wanted)})
+
+			_, _, err := ReadRemoteFile(url, "")
+			if err == nil {
+				t.Fatal("Expected request to fail with code 502")
+			}
+
+			if clock.TimesSlept() != 1 {
+				t.Fatalf("Expected a single retry, but got %d", clock.TimesSlept())
+			}
+
+			got := clock.SleepPeriods[0]
+			delta := time.Minute
+			if got < wanted-delta || wanted+delta < got {
+				t.Errorf("Expected a retry after roughly %s, but actually waited for %s", wanted, got)
+			}
+		}
+	}
+}
+
+func TestShouldUseExponentialBackoffIfNoRetryHeader(t *testing.T) {
+	MaxRequestDuration = time.Hour * 24
+
+	url := "http://bar"
+	retries := 5
+	_, clock := setUpAllFailures(url, 501, retries, nil)
+
+	_, _, err := ReadRemoteFile(url, "")
+	if err == nil {
+		t.Fatal("Expected request to fail with code 501")
+	}
+
+	if clock.TimesSlept() != retries {
+		t.Fatalf("Expected %d retries, but got %d", retries, clock.TimesSlept())
+	}
+
+	var total time.Duration
+	for _, p := range clock.SleepPeriods {
+		total += p
+	}
+
+	delta := time.Millisecond * 100
+	lower := (1 << retries) * time.Second
+	upper := lower + time.Duration(retries*500)*time.Millisecond
+	if total < lower-delta || upper+delta < total {
+		t.Fatalf("Expected a total sleep time between %s and %s (%d retries, exponential backoff with fuzzing), but waited %s instead", lower, upper, retries, total)
+	}
+}
+
+func TestDeadlineExceeded(t *testing.T) {
+	MaxRequestDuration = time.Second * 8
+
+	url := "http://bar"
+	setUpAllFailures(url, 500, 10, nil)
+
+	_, _, err := ReadRemoteFile(url, "")
+	if err == nil {
+		t.Fatal("Expected request to fail with code 500")
+	}
+
+	wanted := "could not fetch http://bar: unable to complete request to http://bar within 8s"
+	got := err.Error()
+	if wanted != got {
+		t.Fatalf("Expected error %q, but got %q", wanted, got)
+	}
+}
+
+func TestNoRetryOnPermanentError(t *testing.T) {
+	MaxRequestDuration = time.Hour
+
+	url := "http://xyz"
+	_, clock := setUpAllFailures(url, 404, 3, nil)
+
+	_, _, err := ReadRemoteFile(url, "")
+	if err == nil {
+		t.Fatal("Expected request to fail with code 404")
+	}
+
+	wanted := "unexpected status code while reading http://xyz: 404"
+	got := err.Error()
+	if wanted != got {
+		t.Fatalf("Expected error %q, but got %q", wanted, got)
+	}
+
+	if clock.TimesSlept() > 0 {
+		t.Fatalf("Expected no retries for permanent error, but got %d", clock.TimesSlept())
+	}
+}