diff --git a/rest/request.go b/rest/request.go index ef943530..e39b6b9d 100644 --- a/rest/request.go +++ b/rest/request.go @@ -620,7 +620,7 @@ func (r *Request) Watch(ctx context.Context) (watch.Interface, error) { } if err := r.retry.Before(ctx, r); err != nil { - return nil, err + return nil, r.retry.WrapPreviousError(err) } resp, err := client.Do(req) @@ -655,7 +655,7 @@ func (r *Request) Watch(ctx context.Context) (watch.Interface, error) { // we need to return the error object from that. err = transformErr } - return nil, err + return nil, r.retry.WrapPreviousError(err) } } } @@ -865,7 +865,7 @@ func (r *Request) request(ctx context.Context, fn func(*http.Request, *http.Resp } if err := r.retry.Before(ctx, r); err != nil { - return err + return r.retry.WrapPreviousError(err) } resp, err := client.Do(req) updateURLMetrics(ctx, r, resp, err) @@ -895,7 +895,7 @@ func (r *Request) request(ctx context.Context, fn func(*http.Request, *http.Resp return true }() if done { - return err + return r.retry.WrapPreviousError(err) } } } diff --git a/rest/request_test.go b/rest/request_test.go index 3f3f45e6..b9428857 100644 --- a/rest/request_test.go +++ b/rest/request_test.go @@ -2614,6 +2614,30 @@ func TestRequestWatchWithRetryInvokeOrder(t *testing.T) { }) } +func TestRequestWatchWithWrapPreviousError(t *testing.T) { + testWithWrapPreviousError(t, func(ctx context.Context, r *Request) error { + w, err := r.Watch(ctx) + if err == nil { + // in this test the the response body returned by the server is always empty, + // this will cause StreamWatcher.receive() to: + // - return an io.EOF to indicate that the watch closed normally and + // - then close the io.Reader + // since we assert on the number of times 'Close' has been called on the + // body of the response object, we need to wait here to avoid race condition. + <-w.ResultChan() + } + return err + }) +} + +func TestRequestDoWithWrapPreviousError(t *testing.T) { + // both request.Do and request.DoRaw have the same behavior and expectations + testWithWrapPreviousError(t, func(ctx context.Context, r *Request) error { + result := r.Do(ctx) + return result.err + }) +} + func testRequestWithRetry(t *testing.T, key string, doFunc func(ctx context.Context, r *Request)) { type expected struct { attempts int @@ -3126,6 +3150,208 @@ func testWithRetryInvokeOrder(t *testing.T, key string, doFunc func(ctx context. } } +func testWithWrapPreviousError(t *testing.T, doFunc func(ctx context.Context, r *Request) error) { + var ( + containsFormatExpected = "- error from a previous attempt: %s" + nonRetryableErr = errors.New("non retryable error") + ) + + tests := []struct { + name string + maxRetries int + serverReturns []responseErr + expectedErr error + wrapped bool + attemptsExpected int + contains string + }{ + { + name: "success at first attempt", + maxRetries: 2, + serverReturns: []responseErr{ + {response: &http.Response{StatusCode: http.StatusOK}, err: nil}, + }, + attemptsExpected: 1, + expectedErr: nil, + }, + { + name: "success after a series of retry-after from the server", + maxRetries: 2, + serverReturns: []responseErr{ + {response: retryAfterResponse(), err: nil}, + {response: retryAfterResponse(), err: nil}, + {response: &http.Response{StatusCode: http.StatusOK}, err: nil}, + }, + attemptsExpected: 3, + expectedErr: nil, + }, + { + name: "success after a series of retryable errors", + maxRetries: 2, + serverReturns: []responseErr{ + {response: nil, err: io.EOF}, + {response: nil, err: io.EOF}, + {response: &http.Response{StatusCode: http.StatusOK}, err: nil}, + }, + attemptsExpected: 3, + expectedErr: nil, + }, + { + name: "request errors out with a non retryable error", + maxRetries: 2, + serverReturns: []responseErr{ + {response: nil, err: nonRetryableErr}, + }, + attemptsExpected: 1, + expectedErr: nonRetryableErr, + }, + { + name: "request times out after retries, but no previous error", + maxRetries: 2, + serverReturns: []responseErr{ + {response: retryAfterResponse(), err: nil}, + {response: retryAfterResponse(), err: nil}, + {response: nil, err: context.Canceled}, + }, + attemptsExpected: 3, + expectedErr: context.Canceled, + }, + { + name: "request times out after retries, and we have a relevant previous error", + maxRetries: 3, + serverReturns: []responseErr{ + {response: nil, err: io.EOF}, + {response: retryAfterResponse(), err: nil}, + {response: retryAfterResponse(), err: nil}, + {response: nil, err: context.Canceled}, + }, + attemptsExpected: 4, + wrapped: true, + expectedErr: context.Canceled, + contains: fmt.Sprintf(containsFormatExpected, io.EOF), + }, + { + name: "interleaved retry-after responses with retryable errors", + maxRetries: 8, + serverReturns: []responseErr{ + {response: retryAfterResponse(), err: nil}, + {response: retryAfterResponse(), err: nil}, + {response: nil, err: io.ErrUnexpectedEOF}, + {response: retryAfterResponse(), err: nil}, + {response: retryAfterResponse(), err: nil}, + {response: nil, err: io.EOF}, + {response: retryAfterResponse(), err: nil}, + {response: retryAfterResponse(), err: nil}, + {response: nil, err: context.Canceled}, + }, + attemptsExpected: 9, + wrapped: true, + expectedErr: context.Canceled, + contains: fmt.Sprintf(containsFormatExpected, io.EOF), + }, + { + name: "request errors out with a retryable error, followed by a non-retryable one", + maxRetries: 3, + serverReturns: []responseErr{ + {response: nil, err: io.EOF}, + {response: nil, err: nonRetryableErr}, + }, + attemptsExpected: 2, + wrapped: true, + expectedErr: nonRetryableErr, + contains: fmt.Sprintf(containsFormatExpected, io.EOF), + }, + { + name: "use the most recent error", + maxRetries: 2, + serverReturns: []responseErr{ + {response: nil, err: io.ErrUnexpectedEOF}, + {response: nil, err: io.EOF}, + {response: nil, err: context.Canceled}, + }, + attemptsExpected: 3, + wrapped: true, + expectedErr: context.Canceled, + contains: fmt.Sprintf(containsFormatExpected, io.EOF), + }, + } + + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + var attempts int + client := clientForFunc(func(req *http.Request) (*http.Response, error) { + defer func() { + attempts++ + }() + + resp := test.serverReturns[attempts].response + if resp != nil { + resp.Body = ioutil.NopCloser(bytes.NewReader([]byte{})) + } + return resp, test.serverReturns[attempts].err + }) + + base, err := url.Parse("http://foo.bar") + if err != nil { + t.Fatalf("Failed to create new HTTP request - %v", err) + } + req := &Request{ + verb: "GET", + body: bytes.NewReader([]byte{}), + c: &RESTClient{ + base: base, + content: defaultContentConfig(), + Client: client, + }, + pathPrefix: "/api/v1", + rateLimiter: flowcontrol.NewFakeAlwaysRateLimiter(), + backoff: &noSleepBackOff{}, + retry: &withRetry{maxRetries: test.maxRetries}, + } + + err = doFunc(context.Background(), req) + if test.attemptsExpected != attempts { + t.Errorf("Expected attempts: %d, but got: %d", test.attemptsExpected, attempts) + } + + switch { + case test.expectedErr == nil: + if err != nil { + t.Errorf("Expected a nil error, but got: %v", err) + return + } + case test.expectedErr != nil: + if !strings.Contains(err.Error(), test.contains) { + t.Errorf("Expected error message to contain %q, but got: %v", test.contains, err) + } + + urlErrGot, _ := err.(*url.Error) + if test.wrapped { + // we expect the url.Error from net/http to be wrapped by WrapPreviousError + unwrapper, ok := err.(interface { + Unwrap() error + }) + if !ok { + t.Errorf("Expected error to implement Unwrap method, but got: %v", err) + return + } + urlErrGot, _ = unwrapper.Unwrap().(*url.Error) + } + // we always get a url.Error from net/http + if urlErrGot == nil { + t.Errorf("Expected error to be url.Error, but got: %v", err) + return + } + + errGot := urlErrGot.Unwrap() + if test.expectedErr != errGot { + t.Errorf("Expected error %v, but got: %v", test.expectedErr, errGot) + } + } + }) + } +} + func TestReuseRequest(t *testing.T) { var tests = []struct { name string diff --git a/rest/with_retry.go b/rest/with_retry.go index 11b9b522..e729ad1e 100644 --- a/rest/with_retry.go +++ b/rest/with_retry.go @@ -22,6 +22,7 @@ import ( "io" "io/ioutil" "net/http" + "net/url" "time" "k8s.io/klog/v2" @@ -83,6 +84,22 @@ type WithRetry interface { // After should be invoked immediately after an attempt is made. After(ctx context.Context, r *Request, resp *http.Response, err error) + + // WrapPreviousError wraps the error from any previous attempt into + // the final error specified in 'finalErr', so the user has more + // context why the request failed. + // For example, if a request times out after multiple retries then + // we see a generic context.Canceled or context.DeadlineExceeded + // error which is not very useful in debugging. This function can + // wrap any error from previous attempt(s) to provide more context to + // the user. The error returned in 'err' must satisfy the + // following conditions: + // a: errors.Unwrap(err) = errors.Unwrap(finalErr) if finalErr + // implements Unwrap + // b: errors.Unwrap(err) = finalErr if finalErr does not + // implements Unwrap + // c: errors.Is(err, otherErr) = errors.Is(finalErr, otherErr) + WrapPreviousError(finalErr error) (err error) } // RetryAfter holds information associated with the next retry. @@ -111,6 +128,16 @@ type withRetry struct { // - for consecutive attempts, it is non nil and holds the // retry after parameters for the next attempt to be made. retryAfter *RetryAfter + + // we keep track of two most recent errors, if the most + // recent attempt is labeled as 'N' then: + // - currentErr represents the error returned by attempt N, it + // can be nil if attempt N did not return an error. + // - previousErr represents an error from an attempt 'M' which + // precedes attempt 'N' (N - M >= 1), it is non nil only when: + // - for a sequence of attempt(s) 1..n (n>1), there + // is an attempt k (k