client-go: add more context to request throttle message

Kubernetes-commit: bc66d3d137d3600b117be390ccb253a9dbcde25e
This commit is contained in:
Abu Kashem 2021-02-12 14:39:44 -05:00 committed by Kubernetes Publisher
parent 10def0e245
commit d1fdbcd4dc

View File

@ -577,7 +577,7 @@ func (r Request) finalURLTemplate() url.URL {
return *url
}
func (r *Request) tryThrottle(ctx context.Context) error {
func (r *Request) tryThrottleWithInfo(ctx context.Context, retryInfo string) error {
if r.rateLimiter == nil {
return nil
}
@ -587,19 +587,32 @@ func (r *Request) tryThrottle(ctx context.Context) error {
err := r.rateLimiter.Wait(ctx)
latency := time.Since(now)
var message string
switch {
case len(retryInfo) > 0:
message = fmt.Sprintf("Waited for %v, %s - request: %s:%s", latency, retryInfo, r.verb, r.URL().String())
default:
message = fmt.Sprintf("Waited for %v due to client-side throttling, not priority and fairness, request: %s:%s", latency, r.verb, r.URL().String())
}
if latency > longThrottleLatency {
klog.V(3).Infof("Throttling request took %v, request: %s:%s", latency, r.verb, r.URL().String())
klog.V(3).Info(message)
}
if latency > extraLongThrottleLatency {
// If the rate limiter latency is very high, the log message should be printed at a higher log level,
// but we use a throttled logger to prevent spamming.
globalThrottledLogger.Infof("Throttling request took %v, request: %s:%s", latency, r.verb, r.URL().String())
globalThrottledLogger.Infof(message)
}
metrics.RateLimiterLatency.Observe(r.verb, r.finalURLTemplate(), latency)
return err
}
func (r *Request) tryThrottle(ctx context.Context) error {
return r.tryThrottleWithInfo(ctx, "")
}
type throttleSettings struct {
logLevel klog.Level
minLogInterval time.Duration
@ -869,6 +882,7 @@ func (r *Request) request(ctx context.Context, fn func(*http.Request, *http.Resp
// Right now we make about ten retry attempts if we get a Retry-After response.
retries := 0
var retryInfo string
for {
url := r.URL().String()
@ -884,9 +898,10 @@ func (r *Request) request(ctx context.Context, fn func(*http.Request, *http.Resp
// We are retrying the request that we already send to apiserver
// at least once before.
// This request should also be throttled with the client-internal rate limiter.
if err := r.tryThrottle(ctx); err != nil {
if err := r.tryThrottleWithInfo(ctx, retryInfo); err != nil {
return err
}
retryInfo = ""
}
resp, err := client.Do(req)
updateURLMetrics(r, resp, err)
@ -931,6 +946,7 @@ func (r *Request) request(ctx context.Context, fn func(*http.Request, *http.Resp
retries++
if seconds, wait := checkWait(resp); wait && retries <= r.maxRetries {
retryInfo = getRetryReason(retries, seconds, resp, err)
if seeker, ok := r.body.(io.Seeker); ok && r.body != nil {
_, err := seeker.Seek(0, 0)
if err != nil {
@ -1204,6 +1220,26 @@ func retryAfterSeconds(resp *http.Response) (int, bool) {
return 0, false
}
func getRetryReason(retries, seconds int, resp *http.Response, err error) string {
// priority and fairness sets the UID of the FlowSchema associated with a request
// in the following response Header.
const responseHeaderMatchedFlowSchemaUID = "X-Kubernetes-PF-FlowSchema-UID"
message := fmt.Sprintf("retries: %d, retry-after: %ds", retries, seconds)
switch {
case resp.StatusCode == http.StatusTooManyRequests:
// it is server-side throttling from priority and fairness
flowSchemaUID := resp.Header.Get(responseHeaderMatchedFlowSchemaUID)
return fmt.Sprintf("%s - retry-reason: due to server-side throttling, FlowSchema UID: %q", message, flowSchemaUID)
case err != nil:
// it's a retriable error
return fmt.Sprintf("%s - retry-reason: due to retriable error, error: %v", message, err)
default:
return fmt.Sprintf("%s - retry-reason: %d", message, resp.StatusCode)
}
}
// Result contains the result of calling Request.Do().
type Result struct {
body []byte