Update retryablehttp to fix a data race (#9551)

This commit is contained in:
ncabatoff
2020-08-31 11:10:52 -04:00
committed by GitHub
parent f4bbf62262
commit a7183b1edb
9 changed files with 163 additions and 59 deletions

2
go.mod
View File

@@ -60,7 +60,7 @@ require (
github.com/hashicorp/go-msgpack v0.5.5 github.com/hashicorp/go-msgpack v0.5.5
github.com/hashicorp/go-multierror v1.1.0 github.com/hashicorp/go-multierror v1.1.0
github.com/hashicorp/go-raftchunking v0.6.3-0.20191002164813-7e9e8525653a github.com/hashicorp/go-raftchunking v0.6.3-0.20191002164813-7e9e8525653a
github.com/hashicorp/go-retryablehttp v0.6.6 github.com/hashicorp/go-retryablehttp v0.6.7
github.com/hashicorp/go-rootcerts v1.0.2 github.com/hashicorp/go-rootcerts v1.0.2
github.com/hashicorp/go-sockaddr v1.0.2 github.com/hashicorp/go-sockaddr v1.0.2
github.com/hashicorp/go-syslog v1.0.0 github.com/hashicorp/go-syslog v1.0.0

7
go.sum
View File

@@ -374,6 +374,7 @@ github.com/google/go-cmp v0.3.0/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMyw
github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU= github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU=
github.com/google/go-cmp v0.4.0 h1:xsAVV57WRhGj6kEIi8ReJzQlHHqcBYCElAvkovg3B/4= github.com/google/go-cmp v0.4.0 h1:xsAVV57WRhGj6kEIi8ReJzQlHHqcBYCElAvkovg3B/4=
github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
github.com/google/go-cmp v0.5.0 h1:/QaMHBdZ26BB3SSst0Iwl10Epc+xhTquomWX0oZEB6w=
github.com/google/go-cmp v0.5.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
github.com/google/go-github v17.0.0+incompatible h1:N0LgJ1j65A7kfXrZnUDaYCs/Sf4rEjNlfyDHW9dolSY= github.com/google/go-github v17.0.0+incompatible h1:N0LgJ1j65A7kfXrZnUDaYCs/Sf4rEjNlfyDHW9dolSY=
github.com/google/go-github v17.0.0+incompatible/go.mod h1:zLgOLi98H3fifZn+44m+umXrS52loVEgC2AApnigrVQ= github.com/google/go-github v17.0.0+incompatible/go.mod h1:zLgOLi98H3fifZn+44m+umXrS52loVEgC2AApnigrVQ=
@@ -486,6 +487,12 @@ github.com/hashicorp/go-retryablehttp v0.6.2 h1:bHM2aVXwBtBJWxHtkSrWuI4umABCUczs
github.com/hashicorp/go-retryablehttp v0.6.2/go.mod h1:gEx6HMUGxYYhJScX7W1Il64m6cc2C1mDaW3NQ9sY1FY= github.com/hashicorp/go-retryablehttp v0.6.2/go.mod h1:gEx6HMUGxYYhJScX7W1Il64m6cc2C1mDaW3NQ9sY1FY=
github.com/hashicorp/go-retryablehttp v0.6.6 h1:HJunrbHTDDbBb/ay4kxa1n+dLmttUlnP3V9oNE4hmsM= github.com/hashicorp/go-retryablehttp v0.6.6 h1:HJunrbHTDDbBb/ay4kxa1n+dLmttUlnP3V9oNE4hmsM=
github.com/hashicorp/go-retryablehttp v0.6.6/go.mod h1:vAew36LZh98gCBJNLH42IQ1ER/9wtLZZ8meHqQvEYWY= github.com/hashicorp/go-retryablehttp v0.6.6/go.mod h1:vAew36LZh98gCBJNLH42IQ1ER/9wtLZZ8meHqQvEYWY=
github.com/hashicorp/go-retryablehttp v0.6.7-0.20200721161721-0321369f5ae5 h1:5TSzdrlZZIR4v20yFQ27rfIqpJqDHlQxBZSdbcpVJ4E=
github.com/hashicorp/go-retryablehttp v0.6.7-0.20200721161721-0321369f5ae5/go.mod h1:vAew36LZh98gCBJNLH42IQ1ER/9wtLZZ8meHqQvEYWY=
github.com/hashicorp/go-retryablehttp v0.6.7-0.20200807182356-37b3e74def02 h1:ge34nim2FF6+u3uWkQX7QvLBgucVCIqIUfa0i3dGX/g=
github.com/hashicorp/go-retryablehttp v0.6.7-0.20200807182356-37b3e74def02/go.mod h1:vAew36LZh98gCBJNLH42IQ1ER/9wtLZZ8meHqQvEYWY=
github.com/hashicorp/go-retryablehttp v0.6.7 h1:8/CAEZt/+F7kR7GevNHulKkUjLht3CPmn7egmhieNKo=
github.com/hashicorp/go-retryablehttp v0.6.7/go.mod h1:vAew36LZh98gCBJNLH42IQ1ER/9wtLZZ8meHqQvEYWY=
github.com/hashicorp/go-rootcerts v1.0.1/go.mod h1:pqUvnprVnM5bf7AOirdbb01K4ccR319Vf4pU3K5EGc8= github.com/hashicorp/go-rootcerts v1.0.1/go.mod h1:pqUvnprVnM5bf7AOirdbb01K4ccR319Vf4pU3K5EGc8=
github.com/hashicorp/go-rootcerts v1.0.2 h1:jzhAVGtqPKbwpyCPELlgNWhE1znq+qwJtW5Oi2viEzc= github.com/hashicorp/go-rootcerts v1.0.2 h1:jzhAVGtqPKbwpyCPELlgNWhE1znq+qwJtW5Oi2viEzc=
github.com/hashicorp/go-rootcerts v1.0.2/go.mod h1:pqUvnprVnM5bf7AOirdbb01K4ccR319Vf4pU3K5EGc8= github.com/hashicorp/go-rootcerts v1.0.2/go.mod h1:pqUvnprVnM5bf7AOirdbb01K4ccR319Vf4pU3K5EGc8=

View File

@@ -71,7 +71,7 @@ func rateLimitQuotaWrapping(handler http.Handler, core *vault.Core) http.Handler
respondError(w, http.StatusTooManyRequests, quotaErr) respondError(w, http.StatusTooManyRequests, quotaErr)
if core.Logger().IsTrace() { if core.Logger().IsTrace() {
core.Logger().Trace("request rejected due to lease count quota violation", "request_path", path) core.Logger().Trace("request rejected due to rate limit quota violation", "request_path", path)
} }
if core.RateLimitAuditLoggingEnabled() { if core.RateLimitAuditLoggingEnabled() {

View File

@@ -1,6 +1,7 @@
package client package client
import ( import (
"errors"
"os" "os"
"testing" "testing"
@@ -56,8 +57,11 @@ func (e *env) TestGetPodNotFound(t *testing.T) {
if err == nil { if err == nil {
t.Fatal("expected error because pod is unfound") t.Fatal("expected error because pod is unfound")
} }
if wrapped := errors.Unwrap(err); wrapped != nil {
err = wrapped
}
if _, ok := err.(*ErrNotFound); !ok { if _, ok := err.(*ErrNotFound); !ok {
t.Fatalf("expected *ErrNotFound but received %T", err) t.Fatalf("expected *ErrNotFound but received %T (%s)", err, err)
} }
} }
@@ -89,6 +93,9 @@ func (e *env) TestUpdatePodTagsNotFound(t *testing.T) {
if err == nil { if err == nil {
t.Fatal("expected error because pod is unfound") t.Fatal("expected error because pod is unfound")
} }
if wrapped := errors.Unwrap(err); wrapped != nil {
err = wrapped
}
if _, ok := err.(*ErrNotFound); !ok { if _, ok := err.(*ErrNotFound); !ok {
t.Fatalf("expected *ErrNotFound but received %T", err) t.Fatalf("expected *ErrNotFound but received %T", err)
} }

View File

@@ -236,7 +236,7 @@ func TestQuotas_RateLimitQuota_Mount(t *testing.T) {
// update the rate limit quota with a high RPS such that no requests should fail // update the rate limit quota with a high RPS such that no requests should fail
_, err = client.Logical().Write("sys/quotas/rate-limit/rlq", map[string]interface{}{ _, err = client.Logical().Write("sys/quotas/rate-limit/rlq", map[string]interface{}{
"rate": 1000.0, "rate": 10000.0,
"path": "pki/", "path": "pki/",
}) })
if err != nil { if err != nil {
@@ -400,7 +400,7 @@ func TestQuotas_RateLimitQuota(t *testing.T) {
// update the rate limit quota with a high RPS such that no requests should fail // update the rate limit quota with a high RPS such that no requests should fail
_, err = client.Logical().Write("sys/quotas/rate-limit/rlq", map[string]interface{}{ _, err = client.Logical().Write("sys/quotas/rate-limit/rlq", map[string]interface{}{
"rate": 1000.0, "rate": 10000.0,
}) })
if err != nil { if err != nil {
t.Fatal(err) t.Fatal(err)

View File

@@ -1,12 +0,0 @@
sudo: false
language: go
go:
- 1.12.4
branches:
only:
- master
script: make updatedeps test

View File

@@ -35,11 +35,12 @@ import (
"net/url" "net/url"
"os" "os"
"regexp" "regexp"
"strconv"
"strings" "strings"
"sync" "sync"
"time" "time"
"github.com/hashicorp/go-cleanhttp" cleanhttp "github.com/hashicorp/go-cleanhttp"
) )
var ( var (
@@ -276,12 +277,16 @@ type Logger interface {
Printf(string, ...interface{}) Printf(string, ...interface{})
} }
// LeveledLogger interface implements the basic methods that a logger library needs // LeveledLogger is an interface that can be implemented by any logger or a
// logger wrapper to provide leveled logging. The methods accept a message
// string and a variadic number of key-value pairs. For log.Printf style
// formatting where message string contains a format specifier, use Logger
// interface.
type LeveledLogger interface { type LeveledLogger interface {
Error(string, ...interface{}) Error(msg string, keysAndValues ...interface{})
Info(string, ...interface{}) Info(msg string, keysAndValues ...interface{})
Debug(string, ...interface{}) Debug(msg string, keysAndValues ...interface{})
Warn(string, ...interface{}) Warn(msg string, keysAndValues ...interface{})
} }
// hookLogger adapts an LeveledLogger to Logger for use by the existing hook functions // hookLogger adapts an LeveledLogger to Logger for use by the existing hook functions
@@ -357,6 +362,7 @@ type Client struct {
ErrorHandler ErrorHandler ErrorHandler ErrorHandler
loggerInit sync.Once loggerInit sync.Once
clientInit sync.Once
} }
// NewClient creates a new Client with default settings. // NewClient creates a new Client with default settings.
@@ -420,6 +426,13 @@ func DefaultRetryPolicy(ctx context.Context, resp *http.Response, err error) (bo
return true, nil return true, nil
} }
// 429 Too Many Requests is recoverable. Sometimes the server puts
// a Retry-After response header to indicate when the server is
// available to start processing request from client.
if resp.StatusCode == http.StatusTooManyRequests {
return true, nil
}
// Check the response code. We retry on 500-range responses to allow // Check the response code. We retry on 500-range responses to allow
// the server time to recover, as 500's are typically not permanent // the server time to recover, as 500's are typically not permanent
// errors and may relate to outages on the server side. This will catch // errors and may relate to outages on the server side. This will catch
@@ -431,10 +444,66 @@ func DefaultRetryPolicy(ctx context.Context, resp *http.Response, err error) (bo
return false, nil return false, nil
} }
// ErrorPropagatedRetryPolicy is the same as DefaultRetryPolicy, except it
// propagates errors back instead of returning nil. This allows you to inspect
// why it decided to retry or not.
func ErrorPropagatedRetryPolicy(ctx context.Context, resp *http.Response, err error) (bool, error) {
// do not retry on context.Canceled or context.DeadlineExceeded
if ctx.Err() != nil {
return false, ctx.Err()
}
if err != nil {
if v, ok := err.(*url.Error); ok {
// Don't retry if the error was due to too many redirects.
if redirectsErrorRe.MatchString(v.Error()) {
return false, v
}
// Don't retry if the error was due to an invalid protocol scheme.
if schemeErrorRe.MatchString(v.Error()) {
return false, v
}
// Don't retry if the error was due to TLS cert verification failure.
if _, ok := v.Err.(x509.UnknownAuthorityError); ok {
return false, v
}
}
// The error is likely recoverable so retry.
return true, nil
}
// Check the response code. We retry on 500-range responses to allow
// the server time to recover, as 500's are typically not permanent
// errors and may relate to outages on the server side. This will catch
// invalid response codes as well, like 0 and 999.
if resp.StatusCode == 0 || (resp.StatusCode >= 500 && resp.StatusCode != 501) {
return true, fmt.Errorf("unexpected HTTP status %s", resp.Status)
}
return false, nil
}
// DefaultBackoff provides a default callback for Client.Backoff which // DefaultBackoff provides a default callback for Client.Backoff which
// will perform exponential backoff based on the attempt number and limited // will perform exponential backoff based on the attempt number and limited
// by the provided minimum and maximum durations. // by the provided minimum and maximum durations.
//
// It also tries to parse Retry-After response header when a http.StatusTooManyRequests
// (HTTP Code 429) is found in the resp parameter. Hence it will return the number of
// seconds the server states it may be ready to process more requests from this client.
func DefaultBackoff(min, max time.Duration, attemptNum int, resp *http.Response) time.Duration { func DefaultBackoff(min, max time.Duration, attemptNum int, resp *http.Response) time.Duration {
if resp != nil {
if resp.StatusCode == http.StatusTooManyRequests {
if s, ok := resp.Header["Retry-After"]; ok {
if sleep, err := strconv.ParseInt(s[0], 10, 64); err == nil {
return time.Second * time.Duration(sleep)
}
}
}
}
mult := math.Pow(2, float64(attemptNum)) * float64(min) mult := math.Pow(2, float64(attemptNum)) * float64(min)
sleep := time.Duration(mult) sleep := time.Duration(mult)
if float64(sleep) != mult || sleep > max { if float64(sleep) != mult || sleep > max {
@@ -490,25 +559,31 @@ func PassthroughErrorHandler(resp *http.Response, err error, _ int) (*http.Respo
// Do wraps calling an HTTP method with retries. // Do wraps calling an HTTP method with retries.
func (c *Client) Do(req *Request) (*http.Response, error) { func (c *Client) Do(req *Request) (*http.Response, error) {
c.clientInit.Do(func() {
if c.HTTPClient == nil { if c.HTTPClient == nil {
c.HTTPClient = cleanhttp.DefaultPooledClient() c.HTTPClient = cleanhttp.DefaultPooledClient()
} }
})
logger := c.logger() logger := c.logger()
if logger != nil { if logger != nil {
switch v := logger.(type) { switch v := logger.(type) {
case Logger:
v.Printf("[DEBUG] %s %s", req.Method, req.URL)
case LeveledLogger: case LeveledLogger:
v.Debug("performing request", "method", req.Method, "url", req.URL) v.Debug("performing request", "method", req.Method, "url", req.URL)
case Logger:
v.Printf("[DEBUG] %s %s", req.Method, req.URL)
} }
} }
var resp *http.Response var resp *http.Response
var err error var attempt int
var shouldRetry bool
var doErr, checkErr error
for i := 0; ; i++ { for i := 0; ; i++ {
attempt++
var code int // HTTP response code var code int // HTTP response code
// Always rewind the request body when non-nil. // Always rewind the request body when non-nil.
@@ -527,30 +602,30 @@ func (c *Client) Do(req *Request) (*http.Response, error) {
if c.RequestLogHook != nil { if c.RequestLogHook != nil {
switch v := logger.(type) { switch v := logger.(type) {
case Logger:
c.RequestLogHook(v, req.Request, i)
case LeveledLogger: case LeveledLogger:
c.RequestLogHook(hookLogger{v}, req.Request, i) c.RequestLogHook(hookLogger{v}, req.Request, i)
case Logger:
c.RequestLogHook(v, req.Request, i)
default: default:
c.RequestLogHook(nil, req.Request, i) c.RequestLogHook(nil, req.Request, i)
} }
} }
// Attempt the request // Attempt the request
resp, err = c.HTTPClient.Do(req.Request) resp, doErr = c.HTTPClient.Do(req.Request)
if resp != nil { if resp != nil {
code = resp.StatusCode code = resp.StatusCode
} }
// Check if we should continue with retries. // Check if we should continue with retries.
checkOK, checkErr := c.CheckRetry(req.Context(), resp, err) shouldRetry, checkErr = c.CheckRetry(req.Context(), resp, doErr)
if err != nil { if doErr != nil {
switch v := logger.(type) { switch v := logger.(type) {
case Logger:
v.Printf("[ERR] %s %s request failed: %v", req.Method, req.URL, err)
case LeveledLogger: case LeveledLogger:
v.Error("request failed", "error", err, "method", req.Method, "url", req.URL) v.Error("request failed", "error", doErr, "method", req.Method, "url", req.URL)
case Logger:
v.Printf("[ERR] %s %s request failed: %v", req.Method, req.URL, doErr)
} }
} else { } else {
// Call this here to maintain the behavior of logging all requests, // Call this here to maintain the behavior of logging all requests,
@@ -558,23 +633,18 @@ func (c *Client) Do(req *Request) (*http.Response, error) {
if c.ResponseLogHook != nil { if c.ResponseLogHook != nil {
// Call the response logger function if provided. // Call the response logger function if provided.
switch v := logger.(type) { switch v := logger.(type) {
case Logger:
c.ResponseLogHook(v, resp)
case LeveledLogger: case LeveledLogger:
c.ResponseLogHook(hookLogger{v}, resp) c.ResponseLogHook(hookLogger{v}, resp)
case Logger:
c.ResponseLogHook(v, resp)
default: default:
c.ResponseLogHook(nil, resp) c.ResponseLogHook(nil, resp)
} }
} }
} }
// Now decide if we should continue. if !shouldRetry {
if !checkOK { break
if checkErr != nil {
err = checkErr
}
c.HTTPClient.CloseIdleConnections()
return resp, err
} }
// We do this before drainBody because there's no need for the I/O if // We do this before drainBody because there's no need for the I/O if
@@ -585,7 +655,7 @@ func (c *Client) Do(req *Request) (*http.Response, error) {
} }
// We're going to retry, consume any response to reuse the connection. // We're going to retry, consume any response to reuse the connection.
if err == nil && resp != nil { if doErr == nil {
c.drainBody(resp.Body) c.drainBody(resp.Body)
} }
@@ -596,10 +666,10 @@ func (c *Client) Do(req *Request) (*http.Response, error) {
} }
if logger != nil { if logger != nil {
switch v := logger.(type) { switch v := logger.(type) {
case Logger:
v.Printf("[DEBUG] %s: retrying in %s (%d left)", desc, wait, remain)
case LeveledLogger: case LeveledLogger:
v.Debug("retrying request", "request", desc, "timeout", wait, "remaining", remain) v.Debug("retrying request", "request", desc, "timeout", wait, "remaining", remain)
case Logger:
v.Printf("[DEBUG] %s: retrying in %s (%d left)", desc, wait, remain)
} }
} }
select { select {
@@ -608,21 +678,44 @@ func (c *Client) Do(req *Request) (*http.Response, error) {
return nil, req.Context().Err() return nil, req.Context().Err()
case <-time.After(wait): case <-time.After(wait):
} }
// Make shallow copy of http Request so that we can modify its body
// without racing against the closeBody call in persistConn.writeLoop.
httpreq := *req.Request
req.Request = &httpreq
}
// this is the closest we have to success criteria
if doErr == nil && checkErr == nil && !shouldRetry {
return resp, nil
}
defer c.HTTPClient.CloseIdleConnections()
err := doErr
if checkErr != nil {
err = checkErr
} }
if c.ErrorHandler != nil { if c.ErrorHandler != nil {
c.HTTPClient.CloseIdleConnections() return c.ErrorHandler(resp, err, attempt)
return c.ErrorHandler(resp, err, c.RetryMax+1)
} }
// By default, we close the response body and return an error without // By default, we close the response body and return an error without
// returning the response // returning the response
if resp != nil { if resp != nil {
resp.Body.Close() c.drainBody(resp.Body)
} }
c.HTTPClient.CloseIdleConnections()
return nil, fmt.Errorf("%s %s giving up after %d attempts", // this means CheckRetry thought the request was a failure, but didn't
req.Method, req.URL, c.RetryMax+1) // communicate why
if err == nil {
return nil, fmt.Errorf("%s %s giving up after %d attempt(s)",
req.Method, req.URL, attempt)
}
return nil, fmt.Errorf("%s %s giving up after %d attempt(s): %w",
req.Method, req.URL, attempt, err)
} }
// Try to read the response body so we can reuse this connection. // Try to read the response body so we can reuse this connection.
@@ -632,10 +725,10 @@ func (c *Client) drainBody(body io.ReadCloser) {
if err != nil { if err != nil {
if c.logger() != nil { if c.logger() != nil {
switch v := c.logger().(type) { switch v := c.logger().(type) {
case Logger:
v.Printf("[ERR] error reading response body: %v", err)
case LeveledLogger: case LeveledLogger:
v.Error("error reading response body", "error", err) v.Error("error reading response body", "error", err)
case Logger:
v.Printf("[ERR] error reading response body: %v", err)
} }
} }
} }

View File

@@ -1,7 +1,9 @@
package retryablehttp package retryablehttp
import ( import (
"errors"
"net/http" "net/http"
"net/url"
"sync" "sync"
) )
@@ -39,5 +41,12 @@ func (rt *RoundTripper) RoundTrip(req *http.Request) (*http.Response, error) {
} }
// Execute the request. // Execute the request.
return rt.Client.Do(retryableReq) resp, err := rt.Client.Do(retryableReq)
// If we got an error returned by standard library's `Do` method, unwrap it
// otherwise we will wind up erroneously re-nesting the error.
if _, ok := err.(*url.Error); ok {
return resp, errors.Unwrap(err)
}
return resp, err
} }

2
vendor/modules.txt vendored
View File

@@ -413,7 +413,7 @@ github.com/hashicorp/go-plugin/internal/plugin
# github.com/hashicorp/go-raftchunking v0.6.3-0.20191002164813-7e9e8525653a # github.com/hashicorp/go-raftchunking v0.6.3-0.20191002164813-7e9e8525653a
github.com/hashicorp/go-raftchunking github.com/hashicorp/go-raftchunking
github.com/hashicorp/go-raftchunking/types github.com/hashicorp/go-raftchunking/types
# github.com/hashicorp/go-retryablehttp v0.6.6 # github.com/hashicorp/go-retryablehttp v0.6.7
github.com/hashicorp/go-retryablehttp github.com/hashicorp/go-retryablehttp
# github.com/hashicorp/go-rootcerts v1.0.2 # github.com/hashicorp/go-rootcerts v1.0.2
github.com/hashicorp/go-rootcerts github.com/hashicorp/go-rootcerts