add RetryAttempts to AccessLog in JSON format

middlewares/accesslog/logdata.go

@@ -68,6 +68,8 @@ const (
 	GzipRatio = "GzipRatio"
 	// Overhead is the map key used for the processing time overhead caused by Traefik.
 	Overhead = "Overhead"
+	// RetryAttempts is the map key used for the amount of attempts the request was retried.
+	RetryAttempts = "RetryAttempts"
 )
 
 // These are written out in the default case when no config is provided to specify keys of interest.
@@ -110,6 +112,7 @@ func init() {
 	allCoreKeys[GzipRatio] = struct{}{}
 	allCoreKeys[StartLocal] = struct{}{}
 	allCoreKeys[Overhead] = struct{}{}
+	allCoreKeys[RetryAttempts] = struct{}{}
 }
 
 // CoreLogData holds the fields computed from the request/response.

middlewares/accesslog/logger.go

@@ -180,9 +180,11 @@ func usernameIfPresent(theURL *url.URL) string {
 
 // Logging handler to log frontend name, backend name, and elapsed time
 func (l *LogHandler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestReader, crw *captureResponseWriter) {
-
 	core := logDataTable.Core
 
+	if core[RetryAttempts] == nil {
+		core[RetryAttempts] = 0
+	}
 	if crr != nil {
 		core[RequestContentSize] = crr.count
 	}

middlewares/accesslog/logger_test.go

@@ -33,6 +33,7 @@ var (
 	testMethod              = "POST"
 	testReferer             = "testReferer"
 	testUserAgent           = "testUserAgent"
+	testRetryAttempts       = 2
 )
 
 func TestLoggerCLF(t *testing.T) {
@@ -91,6 +92,7 @@ func TestLoggerJSON(t *testing.T) {
 		RequestCount,
 		Duration,
 		Overhead,
+		RetryAttempts,
 		"time",
 		"StartLocal",
 		"StartUTC",
@@ -150,6 +152,8 @@ func TestLoggerJSON(t *testing.T) {
 	assertCount++
 	assert.NotZero(t, jsonData[Overhead].(float64))
 	assertCount++
+	assert.Equal(t, float64(testRetryAttempts), jsonData[RetryAttempts].(float64))
+	assertCount++
 	assert.NotEqual(t, "", jsonData["time"].(string))
 	assertCount++
 	assert.NotEqual(t, "", jsonData["StartLocal"].(string))
@@ -275,4 +279,5 @@ func logWriterTestHandlerFunc(rw http.ResponseWriter, r *http.Request) {
 	logDataTable.Core[BackendURL] = testBackendName
 	logDataTable.Core[OriginStatus] = testStatus
 	logDataTable.Core[OriginContentSize] = testContentSize
+	logDataTable.Core[RetryAttempts] = testRetryAttempts
 }

middlewares/accesslog/save_retries.go

@@ -0,0 +1,19 @@
+package accesslog
+
+import (
+	"net/http"
+)
+
+// SaveRetries is an implementation of RetryListener that stores RetryAttempts in the LogDataTable.
+type SaveRetries struct{}
+
+// Retried implements the RetryListener interface and will be called for each retry that happens.
+func (s *SaveRetries) Retried(req *http.Request, attempt int) {
+	// it is the request attempt x, but the retry attempt is x-1
+	if attempt > 0 {
+		attempt--
+	}
+
+	table := GetLogDataTable(req)
+	table.Core[RetryAttempts] = attempt
+}

middlewares/accesslog/save_retries_test.go

@@ -0,0 +1,48 @@
+package accesslog
+
+import (
+	"context"
+	"fmt"
+	"net/http"
+	"net/http/httptest"
+	"testing"
+)
+
+func TestSaveRetries(t *testing.T) {
+	tests := []struct {
+		requestAttempt         int
+		wantRetryAttemptsInLog int
+	}{
+		{
+			requestAttempt:         0,
+			wantRetryAttemptsInLog: 0,
+		},
+		{
+			requestAttempt:         1,
+			wantRetryAttemptsInLog: 0,
+		},
+		{
+			requestAttempt:         3,
+			wantRetryAttemptsInLog: 2,
+		},
+	}
+
+	for _, test := range tests {
+		test := test
+
+		t.Run(fmt.Sprintf("%d retries", test.requestAttempt), func(t *testing.T) {
+			t.Parallel()
+			saveRetries := &SaveRetries{}
+
+			logDataTable := &LogData{Core: make(CoreLogData)}
+			req := httptest.NewRequest(http.MethodGet, "/some/path", nil)
+			reqWithDataTable := req.WithContext(context.WithValue(req.Context(), DataTableKey, logDataTable))
+
+			saveRetries.Retried(reqWithDataTable, test.requestAttempt)
+
+			if logDataTable.Core[RetryAttempts] != test.wantRetryAttemptsInLog {
+				t.Errorf("got %v in logDataTable, want %v", logDataTable.Core[RetryAttempts], test.wantRetryAttemptsInLog)
+			}
+		})
+	}
+}

middlewares/metrics.go

@@ -56,6 +56,6 @@ type MetricsRetryListener struct {
 }
 
 // Retried tracks the retry in the RequestMetrics implementation.
-func (m *MetricsRetryListener) Retried(attempt int) {
+func (m *MetricsRetryListener) Retried(req *http.Request, attempt int) {
 	m.retryMetrics.RetriesCounter().With("backend", m.backendName).Add(1)
 }

middlewares/metrics_test.go

@@ -1,17 +1,20 @@
 package middlewares
 
 import (
+	"net/http"
+	"net/http/httptest"
 	"reflect"
 	"testing"
 
 	"github.com/go-kit/kit/metrics"
 )
 
 func TestMetricsRetryListener(t *testing.T) {
+	req := httptest.NewRequest(http.MethodGet, "/", nil)
 	retryMetrics := newCollectingRetryMetrics()
 	retryListener := NewMetricsRetryListener(retryMetrics, "backendName")
-	retryListener.Retried(1)
-	retryListener.Retried(2)
+	retryListener.Retried(req, 1)
+	retryListener.Retried(req, 2)
 
 	wantCounterValue := float64(2)
 	if retryMetrics.retryCounter.counterValue != wantCounterValue {

middlewares/retry.go

@@ -60,7 +60,7 @@ func (retry *Retry) ServeHTTP(rw http.ResponseWriter, r *http.Request) {
 		}
 		attempts++
 		log.Debugf("New attempt %d for request: %v", attempts, r.URL)
-		retry.listener.Retried(attempts)
+		retry.listener.Retried(r, attempts)
 	}
 }
 
@@ -93,7 +93,18 @@ func (DefaultNetErrorRecorder) Record(ctx context.Context) {
 type RetryListener interface {
 	// Retried will be called when a retry happens, with the request attempt passed to it.
 	// For the first retry this will be attempt 2.
-	Retried(attempt int)
+	Retried(req *http.Request, attempt int)
+}
+
+// RetryListeners is a convenience type to construct a list of RetryListener and notify
+// each of them about a retry attempt.
+type RetryListeners []RetryListener
+
+// Retried exists to implement the RetryListener interface. It calls Retried on each of its slice entries.
+func (l RetryListeners) Retried(req *http.Request, attempt int) {
+	for _, retryListener := range l {
+		retryListener.Retried(req, attempt)
+	}
 }
 
 // retryResponseRecorder is an implementation of http.ResponseWriter that

middlewares/retry_test.go

@@ -89,6 +89,21 @@ func TestDefaultNetErrorRecorderNilValue(t *testing.T) {
 	}
 }
 
+func TestRetryListeners(t *testing.T) {
+	req := httptest.NewRequest(http.MethodGet, "/", nil)
+	retryListeners := RetryListeners{&countingRetryListener{}, &countingRetryListener{}}
+
+	retryListeners.Retried(req, 1)
+	retryListeners.Retried(req, 1)
+
+	for _, retryListener := range retryListeners {
+		listener := retryListener.(*countingRetryListener)
+		if listener.timesCalled != 2 {
+			t.Errorf("retry listener was called %d times, want %d", listener.timesCalled, 2)
+		}
+	}
+}
+
 // networkFailingHTTPHandler is an http.Handler implementation you can use to test retries.
 type networkFailingHTTPHandler struct {
 	netErrorRecorder NetErrorRecorder
@@ -116,6 +131,6 @@ type countingRetryListener struct {
 	timesCalled int
 }
 
-func (l *countingRetryListener) Retried(attempt int) {
+func (l *countingRetryListener) Retried(req *http.Request, attempt int) {
 	l.timesCalled++
 }

server/server.go

@@ -908,9 +908,10 @@ func (server *Server) loadConfig(configurations types.Configurations, globalConf
 					}
 
 					if globalConfiguration.Retry != nil {
-						retryListener := middlewares.NewMetricsRetryListener(server.metricsRegistry, frontend.Backend)
-						lb = registerRetryMiddleware(lb, globalConfiguration, config, frontend.Backend, retryListener)
+						countServers := len(config.Backends[frontend.Backend].Servers)
+						lb = server.buildRetryMiddleware(lb, globalConfiguration, countServers, frontend.Backend)
 					}
+
 					if server.metricsRegistry.IsEnabled() {
 						n.Use(middlewares.NewMetricsWrapper(server.metricsRegistry, frontend.Backend))
 					}
@@ -1187,20 +1188,21 @@ func stopMetricsClients() {
 	metrics.StopStatsd()
 }
 
-func registerRetryMiddleware(
-	httpHandler http.Handler,
-	globalConfig configuration.GlobalConfiguration,
-	config *types.Configuration,
-	backend string,
-	listener middlewares.RetryListener,
-) http.Handler {
-	retries := len(config.Backends[backend].Servers)
+func (server *Server) buildRetryMiddleware(handler http.Handler, globalConfig configuration.GlobalConfiguration, countServers int, backendName string) http.Handler {
+	retryListeners := middlewares.RetryListeners{}
+	if server.metricsRegistry.IsEnabled() {
+		retryListeners = append(retryListeners, middlewares.NewMetricsRetryListener(server.metricsRegistry, backendName))
+	}
+	if server.accessLoggerMiddleware != nil {
+		retryListeners = append(retryListeners, &accesslog.SaveRetries{})
+	}
+
+	retryAttempts := countServers
 	if globalConfig.Retry.Attempts > 0 {
-		retries = globalConfig.Retry.Attempts
+		retryAttempts = globalConfig.Retry.Attempts
 	}
 
-	httpHandler = middlewares.NewRetry(retries, httpHandler, listener)
-	log.Debugf("Creating retries max attempts %d", retries)
+	log.Debugf("Creating retries max attempts %d", retryAttempts)
 
-	return httpHandler
+	return middlewares.NewRetry(retryAttempts, handler, retryListeners)
 }

server/server_test.go

@@ -495,74 +495,6 @@ func TestConfigureBackends(t *testing.T) {
 	}
 }
 
-func TestRegisterRetryMiddleware(t *testing.T) {
-	testCases := []struct {
-		name            string
-		globalConfig    configuration.GlobalConfiguration
-		countServers    int
-		expectedRetries int
-	}{
-		{
-			name: "configured retry attempts",
-			globalConfig: configuration.GlobalConfiguration{
-				Retry: &configuration.Retry{
-					Attempts: 3,
-				},
-			},
-			expectedRetries: 3,
-		},
-		{
-			name: "retry attempts defaults to server amount",
-			globalConfig: configuration.GlobalConfiguration{
-				Retry: &configuration.Retry{},
-			},
-			expectedRetries: 2,
-		},
-	}
-
-	for _, tc := range testCases {
-		tc := tc
-		t.Run(tc.name, func(t *testing.T) {
-			t.Parallel()
-
-			var retryListener middlewares.RetryListener
-			httpHandler := okHTTPHandler{}
-			dynamicConfig := &types.Configuration{
-				Backends: map[string]*types.Backend{
-					"backend": {
-						Servers: map[string]types.Server{
-							"server": {
-								URL: "http://localhost",
-							},
-							"server2": {
-								URL: "http://localhost",
-							},
-						},
-					},
-				},
-			}
-
-			httpHandlerWithRetry := registerRetryMiddleware(httpHandler, tc.globalConfig, dynamicConfig, "backend", retryListener)
-
-			retry, ok := httpHandlerWithRetry.(*middlewares.Retry)
-			if !ok {
-				t.Fatalf("httpHandler was not decorated with retry httpHandler, got %#v", httpHandlerWithRetry)
-			}
-
-			expectedRetry := middlewares.NewRetry(tc.expectedRetries, httpHandler, retryListener)
-			if !reflect.DeepEqual(retry, expectedRetry) {
-				t.Errorf("retry httpHandler was not instantiated correctly, got %#v want %#v", retry, expectedRetry)
-			}
-		})
-	}
-}
-
-type okHTTPHandler struct{}
-
-func (okHTTPHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
-	w.WriteHeader(http.StatusOK)
-}
-
 func TestServerEntrypointWhitelistConfig(t *testing.T) {
 	tests := []struct {
 		desc           string