From c762b9bb2ed71389dca2d03ff673ae71b2b6a27b Mon Sep 17 00:00:00 2001 From: Marco Jantke Date: Fri, 23 Mar 2018 09:28:03 +0100 Subject: [PATCH] add access log filter for retry attempts --- docs/configuration/logs.md | 13 +++++-- middlewares/accesslog/logger.go | 52 +++++++++++++++------------- middlewares/accesslog/logger_test.go | 20 +++++++++++ types/logs.go | 3 +- types/types.go | 13 ++++++- types/types_test.go | 43 +++++++++++++++++++++++ 6 files changed, 116 insertions(+), 28 deletions(-) diff --git a/docs/configuration/logs.md b/docs/configuration/logs.md index b7b233f95..45c8aca58 100644 --- a/docs/configuration/logs.md +++ b/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,7 +124,7 @@ 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" @@ -130,12 +132,19 @@ 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: diff --git a/middlewares/accesslog/logger.go b/middlewares/accesslog/logger.go index 6bdb07283..09cab0239 100644 --- a/middlewares/accesslog/logger.go +++ b/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 } //------------------------------------------------------------------------------------------------- diff --git a/middlewares/accesslog/logger_test.go b/middlewares/accesslog/logger_test.go index cb1c356c7..1dd93ec7f 100644 --- a/middlewares/accesslog/logger_test.go +++ b/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{ diff --git a/types/logs.go b/types/logs.go index 8705aae0a..4ad2a3902 100644 --- a/types/logs.go +++ b/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 diff --git a/types/types.go b/types/types.go index 81312df91..24ccb6c70 100644 --- a/types/types.go +++ b/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 +} diff --git a/types/types_test.go b/types/types_test.go index 68df6e90a..3973e025d 100644 --- a/types/types_test.go +++ b/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)) + }) + } +}