Add access log filter for retry attempts

docs/configuration/logs.md

@@ -17,6 +17,7 @@ logLevel = "INFO"
 
   [accessLog.filters]
     statusCodes = ["200", "300-302"]
+    retryAttempts = true
 
   [accessLog.fields]
     defaultMode = "keep"
@@ -44,6 +45,7 @@ For more information about the CLI, see the documentation about [Traefik command
 --accessLog.filePath="/path/to/access.log"
 --accessLog.format="json"
 --accessLog.filters.statusCodes="200,300-302"
+--accessLog.filters.retryAttempts="true"
 --accessLog.fields.defaultMode="keep"
 --accessLog.fields.names="Username=drop Hostname=drop"
 --accessLog.fields.headers.defaultMode="keep"
@@ -122,20 +124,27 @@ filePath = "/path/to/access.log"
 format = "json"
 ```
 
-To filter logs by status code:
+To filter logs you can specify a set of filters which are logically "OR-connected". Thus, specifying multiple filters will keep more access logs than specifying only one:
 ```toml
 [accessLog]
 filePath = "/path/to/access.log"
 format = "json"
 
   [accessLog.filters]
 
-  # statusCodes keep only access logs with status codes in the specified range
+  # statusCodes keep access logs with status codes in the specified range
   #
   # Optional
   # Default: []
   #
   statusCodes = ["200", "300-302"]
+
+  # retryAttempts keep access logs when at least one retry happened
+  #
+  # Optional
+  # Default: false
+  #
+  retryAttempts = true
 ```
 
 To customize logs format:

middlewares/accesslog/logger.go

@@ -33,12 +33,11 @@ const (
 
 // LogHandler will write each request and its response to the access log.
 type LogHandler struct {
+	config         *types.AccessLog
 	logger         *logrus.Logger
 	file           *os.File
-	filePath       string
 	mu             sync.Mutex
 	httpCodeRanges types.HTTPCodeRanges
-	fields         *types.AccessLogFields
 }
 
 // NewLogHandler creates a new LogHandler
@@ -71,17 +70,15 @@ func NewLogHandler(config *types.AccessLog) (*LogHandler, error) {
 	}
 
 	logHandler := &LogHandler{
-		logger:   logger,
-		file:     file,
-		filePath: config.FilePath,
-		fields:   config.Fields,
+		config: config,
+		logger: logger,
+		file:   file,
 	}
 
 	if config.Filters != nil {
-		httpCodeRanges, err := types.NewHTTPCodeRanges(config.Filters.StatusCodes)
-		if err != nil {
+		if httpCodeRanges, err := types.NewHTTPCodeRanges(config.Filters.StatusCodes); err != nil {
 			log.Errorf("Failed to create new HTTP code ranges: %s", err)
-		} else if httpCodeRanges != nil {
+		} else {
 			logHandler.httpCodeRanges = httpCodeRanges
 		}
 	}
@@ -178,7 +175,7 @@ func (l *LogHandler) Rotate() error {
 		}(l.file)
 	}
 
-	l.file, err = os.OpenFile(l.filePath, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0664)
+	l.file, err = os.OpenFile(l.config.FilePath, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0664)
 	if err != nil {
 		return err
 	}
@@ -210,16 +207,19 @@ func usernameIfPresent(theURL *url.URL) string {
 func (l *LogHandler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestReader, crw *captureResponseWriter) {
 	core := logDataTable.Core
 
-	if core[RetryAttempts] == nil {
-		core[RetryAttempts] = 0
+	retryAttempts, ok := core[RetryAttempts].(int)
+	if !ok {
+		retryAttempts = 0
 	}
+	core[RetryAttempts] = retryAttempts
+
 	if crr != nil {
 		core[RequestContentSize] = crr.count
 	}
 
 	core[DownstreamStatus] = crw.Status()
 
-	if l.keepAccessLog(crw.Status()) {
+	if l.keepAccessLog(crw.Status(), retryAttempts) {
 		core[DownstreamStatusLine] = fmt.Sprintf("%03d %s", crw.Status(), http.StatusText(crw.Status()))
 		core[DownstreamContentSize] = crw.Size()
 		if original, ok := core[OriginContentSize]; ok {
@@ -240,7 +240,7 @@ func (l *LogHandler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestR
 		fields := logrus.Fields{}
 
 		for k, v := range logDataTable.Core {
-			if l.fields.Keep(k) {
+			if l.config.Fields.Keep(k) {
 				fields[k] = v
 			}
 		}
@@ -257,7 +257,7 @@ func (l *LogHandler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestR
 
 func (l *LogHandler) redactHeaders(headers http.Header, fields logrus.Fields, prefix string) {
 	for k := range headers {
-		v := l.fields.KeepHeader(k)
+		v := l.config.Fields.KeepHeader(k)
 		if v == types.AccessLogKeep {
 			fields[prefix+k] = headers.Get(k)
 		} else if v == types.AccessLogRedact {
@@ -266,17 +266,21 @@ func (l *LogHandler) redactHeaders(headers http.Header, fields logrus.Fields, pr
 	}
 }
 
-func (l *LogHandler) keepAccessLog(status int) bool {
-	if l.httpCodeRanges == nil {
+func (l *LogHandler) keepAccessLog(statusCode, retryAttempts int) bool {
+	switch {
+	case l.config.Filters == nil:
+		// no filters were specified
 		return true
+	case len(l.httpCodeRanges) == 0 && l.config.Filters.RetryAttempts == false:
+		// empty filters were specified, e.g. by passing --accessLog.filters only (without other filter options)
+		return true
+	case l.httpCodeRanges.Contains(statusCode):
+		return true
+	case l.config.Filters.RetryAttempts == true && retryAttempts > 0:
+		return true
+	default:
+		return false
 	}
-
-	for _, block := range l.httpCodeRanges {
-		if status >= block[0] && status <= block[1] {
-			return true
-		}
-	}
-	return false
 }
 
 //-------------------------------------------------------------------------------------------------

middlewares/accesslog/logger_test.go

@@ -335,6 +335,15 @@ func TestNewLogHandlerOutputStdout(t *testing.T) {
 			},
 			expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testFrontend" "http://127.0.0.1/testBackend" 1ms`,
 		},
+		{
+			desc: "default config with empty filters",
+			config: &types.AccessLog{
+				FilePath: "",
+				Format:   CommonFormat,
+				Filters:  &types.AccessLogFilters{},
+			},
+			expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testFrontend" "http://127.0.0.1/testBackend" 1ms`,
+		},
 		{
 			desc: "Status code filter not matching",
 			config: &types.AccessLog{
@@ -357,6 +366,17 @@ func TestNewLogHandlerOutputStdout(t *testing.T) {
 			},
 			expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testFrontend" "http://127.0.0.1/testBackend" 1ms`,
 		},
+		{
+			desc: "Retry attempts filter matching",
+			config: &types.AccessLog{
+				FilePath: "",
+				Format:   CommonFormat,
+				Filters: &types.AccessLogFilters{
+					RetryAttempts: true,
+				},
+			},
+			expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testFrontend" "http://127.0.0.1/testBackend" 1ms`,
+		},
 		{
 			desc: "Default mode keep",
 			config: &types.AccessLog{

types/logs.go

@@ -33,7 +33,8 @@ type StatusCodes []string
 
 // AccessLogFilters holds filters configuration
 type AccessLogFilters struct {
-	StatusCodes StatusCodes `json:"statusCodes,omitempty" description:"Keep only specific ranges of HTTP Status codes" export:"true"`
+	StatusCodes   StatusCodes `json:"statusCodes,omitempty" description:"Keep access logs with status codes in the specified range" export:"true"`
+	RetryAttempts bool        `json:"retryAttempts,omitempty" description:"Keep access logs when at least one retry happened" export:"true"`
 }
 
 // FieldNames holds maps of fields with specific mode

types/types.go

@@ -540,7 +540,7 @@ func (clientTLS *ClientTLS) CreateTLSConfig() (*tls.Config, error) {
 // HTTPCodeRanges holds HTTP code ranges
 type HTTPCodeRanges [][2]int
 
-// NewHTTPCodeRanges create a new NewHTTPCodeRanges from a given []string].
+// NewHTTPCodeRanges creates HTTPCodeRanges from a given []string.
 // Break out the http status code ranges into a low int and high int
 // for ease of use at runtime
 func NewHTTPCodeRanges(strBlocks []string) (HTTPCodeRanges, error) {
@@ -563,3 +563,14 @@ func NewHTTPCodeRanges(strBlocks []string) (HTTPCodeRanges, error) {
 	}
 	return blocks, nil
 }
+
+// Contains tests whether the passed status code is within
+// one of its HTTP code ranges.
+func (h HTTPCodeRanges) Contains(statusCode int) bool {
+	for _, block := range h {
+		if statusCode >= block[0] && statusCode <= block[1] {
+			return true
+		}
+	}
+	return false
+}

types/types_test.go

@@ -1,6 +1,7 @@
 package types
 
 import (
+	"fmt"
 	"testing"
 
 	"github.com/stretchr/testify/assert"
@@ -93,3 +94,45 @@ func TestNewHTTPCodeRanges(t *testing.T) {
 		})
 	}
 }
+
+func TestHTTPCodeRanges_Contains(t *testing.T) {
+	testCases := []struct {
+		strBlocks  []string
+		statusCode int
+		contains   bool
+	}{
+		{
+			strBlocks:  []string{"200-299"},
+			statusCode: 200,
+			contains:   true,
+		},
+		{
+			strBlocks:  []string{"200"},
+			statusCode: 200,
+			contains:   true,
+		},
+		{
+			strBlocks:  []string{"201"},
+			statusCode: 200,
+			contains:   false,
+		},
+		{
+			strBlocks:  []string{"200-299", "500-599"},
+			statusCode: 400,
+			contains:   false,
+		},
+	}
+
+	for _, test := range testCases {
+		test := test
+		testName := fmt.Sprintf("%q contains %d", test.strBlocks, test.statusCode)
+		t.Run(testName, func(t *testing.T) {
+			t.Parallel()
+
+			httpCodeRanges, err := NewHTTPCodeRanges(test.strBlocks)
+			assert.NoError(t, err)
+
+			assert.Equal(t, test.contains, httpCodeRanges.Contains(test.statusCode))
+		})
+	}
+}