1
0
Fork 0

Dynamic Configuration Refactoring

This commit is contained in:
Ludovic Fernandez 2018-11-14 10:18:03 +01:00 committed by Traefiker Bot
parent d3ae88f108
commit a09dfa3ce1
452 changed files with 21023 additions and 9419 deletions

View file

@ -6,7 +6,7 @@ import (
"net"
"net/http"
"github.com/containous/traefik/middlewares"
"github.com/containous/traefik/old/middlewares"
)
var (

View file

@ -0,0 +1,59 @@
package accesslog
import (
"net/http"
"time"
"github.com/vulcand/oxy/utils"
)
// FieldApply function hook to add data in accesslog
type FieldApply func(rw http.ResponseWriter, r *http.Request, next http.Handler, data *LogData)
// FieldHandler sends a new field to the logger.
type FieldHandler struct {
next http.Handler
name string
value string
applyFn FieldApply
}
// NewFieldHandler creates a Field handler.
func NewFieldHandler(next http.Handler, name string, value string, applyFn FieldApply) http.Handler {
return &FieldHandler{next: next, name: name, value: value, applyFn: applyFn}
}
func (f *FieldHandler) ServeHTTP(rw http.ResponseWriter, req *http.Request) {
table := GetLogData(req)
if table == nil {
f.next.ServeHTTP(rw, req)
return
}
table.Core[f.name] = f.value
if f.applyFn != nil {
f.applyFn(rw, req, f.next, table)
} else {
f.next.ServeHTTP(rw, req)
}
}
// AddServiceFields add service fields
func AddServiceFields(rw http.ResponseWriter, req *http.Request, next http.Handler, data *LogData) {
data.Core[ServiceURL] = req.URL // note that this is *not* the original incoming URL
data.Core[ServiceAddr] = req.URL.Host
crw := &captureResponseWriter{rw: rw}
start := time.Now().UTC()
next.ServeHTTP(crw, req)
// use UTC to handle switchover of daylight saving correctly
data.Core[OriginDuration] = time.Now().UTC().Sub(start)
data.Core[OriginStatus] = crw.Status()
// make copy of headers so we can ensure there is no subsequent mutation during response processing
data.OriginResponse = make(http.Header)
utils.CopyHeaders(data.OriginResponse, crw.Header())
data.Core[OriginContentSize] = crw.Size()
}

View file

@ -12,14 +12,16 @@ const (
// Duration is the map key used for the total time taken by processing the response, including the origin server's time but
// not the log writing time.
Duration = "Duration"
// FrontendName is the map key used for the name of the Traefik frontend.
FrontendName = "FrontendName"
// BackendName is the map key used for the name of the Traefik backend.
BackendName = "BackendName"
// BackendURL is the map key used for the URL of the Traefik backend.
BackendURL = "BackendURL"
// BackendAddr is the map key used for the IP:port of the Traefik backend (extracted from BackendURL)
BackendAddr = "BackendAddr"
// RouterName is the map key used for the name of the Traefik router.
RouterName = "RouterName"
// ServiceName is the map key used for the name of the Traefik backend.
ServiceName = "ServiceName"
// ServiceURL is the map key used for the URL of the Traefik backend.
ServiceURL = "ServiceURL"
// ServiceAddr is the map key used for the IP:port of the Traefik backend (extracted from BackendURL)
ServiceAddr = "ServiceAddr"
// ClientAddr is the map key used for the remote address in its original form (usually IP:port).
ClientAddr = "ClientAddr"
// ClientHost is the map key used for the remote IP address from which the client request was received.
@ -72,9 +74,9 @@ const (
var defaultCoreKeys = [...]string{
StartUTC,
Duration,
FrontendName,
BackendName,
BackendURL,
RouterName,
ServiceName,
ServiceURL,
ClientHost,
ClientPort,
ClientUsername,
@ -99,7 +101,7 @@ func init() {
for _, k := range defaultCoreKeys {
allCoreKeys[k] = struct{}{}
}
allCoreKeys[BackendAddr] = struct{}{}
allCoreKeys[ServiceAddr] = struct{}{}
allCoreKeys[ClientAddr] = struct{}{}
allCoreKeys[RequestAddr] = struct{}{}
allCoreKeys[GzipRatio] = struct{}{}

View file

@ -12,6 +12,7 @@ import (
"sync/atomic"
"time"
"github.com/containous/alice"
"github.com/containous/flaeg/parse"
"github.com/containous/traefik/log"
"github.com/containous/traefik/types"
@ -21,36 +22,44 @@ import (
type key string
const (
// DataTableKey is the key within the request context used to
// store the Log Data Table
// DataTableKey is the key within the request context used to store the Log Data Table.
DataTableKey key = "LogDataTable"
// CommonFormat is the common logging format (CLF)
// CommonFormat is the common logging format (CLF).
CommonFormat string = "common"
// JSONFormat is the JSON logging format
// JSONFormat is the JSON logging format.
JSONFormat string = "json"
)
type logHandlerParams struct {
type handlerParams struct {
logDataTable *LogData
crr *captureRequestReader
crw *captureResponseWriter
}
// LogHandler will write each request and its response to the access log.
type LogHandler struct {
// Handler will write each request and its response to the access log.
type Handler struct {
config *types.AccessLog
logger *logrus.Logger
file *os.File
mu sync.Mutex
httpCodeRanges types.HTTPCodeRanges
logHandlerChan chan logHandlerParams
logHandlerChan chan handlerParams
wg sync.WaitGroup
}
// NewLogHandler creates a new LogHandler
func NewLogHandler(config *types.AccessLog) (*LogHandler, error) {
// WrapHandler Wraps access log handler into an Alice Constructor.
func WrapHandler(handler *Handler) alice.Constructor {
return func(next http.Handler) (http.Handler, error) {
return http.HandlerFunc(func(rw http.ResponseWriter, req *http.Request) {
handler.ServeHTTP(rw, req, next.ServeHTTP)
}), nil
}
}
// NewHandler creates a new Handler.
func NewHandler(config *types.AccessLog) (*Handler, error) {
file := os.Stdout
if len(config.FilePath) > 0 {
f, err := openAccessLogFile(config.FilePath)
@ -59,7 +68,7 @@ func NewLogHandler(config *types.AccessLog) (*LogHandler, error) {
}
file = f
}
logHandlerChan := make(chan logHandlerParams, config.BufferingSize)
logHandlerChan := make(chan handlerParams, config.BufferingSize)
var formatter logrus.Formatter
@ -79,7 +88,7 @@ func NewLogHandler(config *types.AccessLog) (*LogHandler, error) {
Level: logrus.InfoLevel,
}
logHandler := &LogHandler{
logHandler := &Handler{
config: config,
logger: logger,
file: file,
@ -88,7 +97,7 @@ func NewLogHandler(config *types.AccessLog) (*LogHandler, error) {
if config.Filters != nil {
if httpCodeRanges, err := types.NewHTTPCodeRanges(config.Filters.StatusCodes); err != nil {
log.Errorf("Failed to create new HTTP code ranges: %s", err)
log.WithoutContext().Errorf("Failed to create new HTTP code ranges: %s", err)
} else {
logHandler.httpCodeRanges = httpCodeRanges
}
@ -122,17 +131,16 @@ func openAccessLogFile(filePath string) (*os.File, error) {
return file, nil
}
// GetLogDataTable gets the request context object that contains logging data.
// GetLogData gets the request context object that contains logging data.
// This creates data as the request passes through the middleware chain.
func GetLogDataTable(req *http.Request) *LogData {
func GetLogData(req *http.Request) *LogData {
if ld, ok := req.Context().Value(DataTableKey).(*LogData); ok {
return ld
}
log.Errorf("%s is nil", DataTableKey)
return &LogData{Core: make(CoreLogData)}
return nil
}
func (l *LogHandler) ServeHTTP(rw http.ResponseWriter, req *http.Request, next http.HandlerFunc) {
func (h *Handler) ServeHTTP(rw http.ResponseWriter, req *http.Request, next http.HandlerFunc) {
now := time.Now().UTC()
core := CoreLogData{
@ -179,46 +187,45 @@ func (l *LogHandler) ServeHTTP(rw http.ResponseWriter, req *http.Request, next h
next.ServeHTTP(crw, reqWithDataTable)
core[ClientUsername] = formatUsernameForLog(core[ClientUsername])
core[ClientUsername] = usernameIfPresent(reqWithDataTable.URL)
logDataTable.DownstreamResponse = crw.Header()
if l.config.BufferingSize > 0 {
l.logHandlerChan <- logHandlerParams{
if h.config.BufferingSize > 0 {
h.logHandlerChan <- handlerParams{
logDataTable: logDataTable,
crr: crr,
crw: crw,
}
} else {
l.logTheRoundTrip(logDataTable, crr, crw)
h.logTheRoundTrip(logDataTable, crr, crw)
}
}
// Close closes the Logger (i.e. the file, drain logHandlerChan, etc).
func (l *LogHandler) Close() error {
close(l.logHandlerChan)
l.wg.Wait()
return l.file.Close()
func (h *Handler) Close() error {
close(h.logHandlerChan)
h.wg.Wait()
return h.file.Close()
}
// Rotate closes and reopens the log file to allow for rotation
// by an external source.
func (l *LogHandler) Rotate() error {
// Rotate closes and reopens the log file to allow for rotation by an external source.
func (h *Handler) Rotate() error {
var err error
if l.file != nil {
if h.file != nil {
defer func(f *os.File) {
f.Close()
}(l.file)
}(h.file)
}
l.file, err = os.OpenFile(l.config.FilePath, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0664)
h.file, err = os.OpenFile(h.config.FilePath, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0664)
if err != nil {
return err
}
l.mu.Lock()
defer l.mu.Unlock()
l.logger.Out = l.file
h.mu.Lock()
defer h.mu.Unlock()
h.logger.Out = h.file
return nil
}
@ -230,16 +237,17 @@ func silentSplitHostPort(value string) (host string, port string) {
return host, port
}
func formatUsernameForLog(usernameField interface{}) string {
username, ok := usernameField.(string)
if ok && len(username) != 0 {
return username
func usernameIfPresent(theURL *url.URL) string {
if theURL.User != nil {
if name := theURL.User.Username(); name != "" {
return name
}
}
return "-"
}
// Logging handler to log frontend name, backend name, and elapsed time
func (l *LogHandler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestReader, crw *captureResponseWriter) {
// Logging handler to log frontend name, backend name, and elapsed time.
func (h *Handler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestReader, crw *captureResponseWriter) {
core := logDataTable.Core
retryAttempts, ok := core[RetryAttempts].(int)
@ -254,11 +262,11 @@ func (l *LogHandler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestR
core[DownstreamStatus] = crw.Status()
// n.b. take care to perform time arithmetic using UTC to avoid errors at DST boundaries
// n.b. take care to perform time arithmetic using UTC to avoid errors at DST boundaries.
totalDuration := time.Now().UTC().Sub(core[StartUTC].(time.Time))
core[Duration] = totalDuration
if l.keepAccessLog(crw.Status(), retryAttempts, totalDuration) {
if h.keepAccessLog(crw.Status(), retryAttempts, totalDuration) {
core[DownstreamContentSize] = crw.Size()
if original, ok := core[OriginContentSize]; ok {
o64 := original.(int64)
@ -275,24 +283,24 @@ func (l *LogHandler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestR
fields := logrus.Fields{}
for k, v := range logDataTable.Core {
if l.config.Fields.Keep(k) {
if h.config.Fields.Keep(k) {
fields[k] = v
}
}
l.redactHeaders(logDataTable.Request, fields, "request_")
l.redactHeaders(logDataTable.OriginResponse, fields, "origin_")
l.redactHeaders(logDataTable.DownstreamResponse, fields, "downstream_")
h.redactHeaders(logDataTable.Request, fields, "request_")
h.redactHeaders(logDataTable.OriginResponse, fields, "origin_")
h.redactHeaders(logDataTable.DownstreamResponse, fields, "downstream_")
l.mu.Lock()
defer l.mu.Unlock()
l.logger.WithFields(fields).Println()
h.mu.Lock()
defer h.mu.Unlock()
h.logger.WithFields(fields).Println()
}
}
func (l *LogHandler) redactHeaders(headers http.Header, fields logrus.Fields, prefix string) {
func (h *Handler) redactHeaders(headers http.Header, fields logrus.Fields, prefix string) {
for k := range headers {
v := l.config.Fields.KeepHeader(k)
v := h.config.Fields.KeepHeader(k)
if v == types.AccessLogKeep {
fields[prefix+k] = headers.Get(k)
} else if v == types.AccessLogRedact {
@ -301,26 +309,26 @@ func (l *LogHandler) redactHeaders(headers http.Header, fields logrus.Fields, pr
}
}
func (l *LogHandler) keepAccessLog(statusCode, retryAttempts int, duration time.Duration) bool {
if l.config.Filters == nil {
func (h *Handler) keepAccessLog(statusCode, retryAttempts int, duration time.Duration) bool {
if h.config.Filters == nil {
// no filters were specified
return true
}
if len(l.httpCodeRanges) == 0 && !l.config.Filters.RetryAttempts && l.config.Filters.MinDuration == 0 {
if len(h.httpCodeRanges) == 0 && !h.config.Filters.RetryAttempts && h.config.Filters.MinDuration == 0 {
// empty filters were specified, e.g. by passing --accessLog.filters only (without other filter options)
return true
}
if l.httpCodeRanges.Contains(statusCode) {
if h.httpCodeRanges.Contains(statusCode) {
return true
}
if l.config.Filters.RetryAttempts && retryAttempts > 0 {
if h.config.Filters.RetryAttempts && retryAttempts > 0 {
return true
}
if l.config.Filters.MinDuration > 0 && (parse.Duration(duration) > l.config.Filters.MinDuration) {
if h.config.Filters.MinDuration > 0 && (parse.Duration(duration) > h.config.Filters.MinDuration) {
return true
}

View file

@ -8,16 +8,16 @@ import (
"github.com/sirupsen/logrus"
)
// default format for time presentation
// default format for time presentation.
const (
commonLogTimeFormat = "02/Jan/2006:15:04:05 -0700"
defaultValue = "-"
)
// CommonLogFormatter provides formatting in the Traefik common log format
// CommonLogFormatter provides formatting in the Traefik common log format.
type CommonLogFormatter struct{}
// Format formats the log entry in the Traefik common log format
// Format formats the log entry in the Traefik common log format.
func (f *CommonLogFormatter) Format(entry *logrus.Entry) ([]byte, error) {
b := &bytes.Buffer{}
@ -43,8 +43,8 @@ func (f *CommonLogFormatter) Format(entry *logrus.Entry) ([]byte, error) {
toLog(entry.Data, "request_Referer", `"-"`, true),
toLog(entry.Data, "request_User-Agent", `"-"`, true),
toLog(entry.Data, RequestCount, defaultValue, true),
toLog(entry.Data, FrontendName, defaultValue, true),
toLog(entry.Data, BackendURL, defaultValue, true),
toLog(entry.Data, RouterName, defaultValue, true),
toLog(entry.Data, ServiceURL, defaultValue, true),
elapsedMillis)
return b.Bytes(), err
@ -70,6 +70,7 @@ func toLog(fields logrus.Fields, key string, defaultValue string, quoted bool) i
return defaultValue
}
func toLogEntry(s string, defaultValue string, quote bool) string {
if len(s) == 0 {
return defaultValue

View file

@ -32,8 +32,8 @@ func TestCommonLogFormatter_Format(t *testing.T) {
RequestRefererHeader: "",
RequestUserAgentHeader: "",
RequestCount: 0,
FrontendName: "",
BackendURL: "",
RouterName: "",
ServiceURL: "",
},
expectedLog: `10.0.0.1 - Client [10/Nov/2009:23:00:00 +0000] "GET /foo http" - - "-" "-" 0 - - 123000ms
`,
@ -53,8 +53,8 @@ func TestCommonLogFormatter_Format(t *testing.T) {
RequestRefererHeader: "referer",
RequestUserAgentHeader: "agent",
RequestCount: nil,
FrontendName: "foo",
BackendURL: "http://10.0.0.2/toto",
RouterName: "foo",
ServiceURL: "http://10.0.0.2/toto",
},
expectedLog: `10.0.0.1 - Client [10/Nov/2009:23:00:00 +0000] "GET /foo http" 123 132 "referer" "agent" - "foo" "http://10.0.0.2/toto" 123000ms
`,

View file

@ -15,7 +15,6 @@ import (
"time"
"github.com/containous/flaeg/parse"
"github.com/containous/traefik/log"
"github.com/containous/traefik/types"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
@ -24,8 +23,8 @@ import (
var (
logFileNameSuffix = "/traefik/logger/test.log"
testContent = "Hello, World"
testBackendName = "http://127.0.0.1/testBackend"
testFrontendName = "testFrontend"
testServiceName = "http://127.0.0.1/testService"
testRouterName = "testRouter"
testStatus = 123
testContentSize int64 = 12
testHostname = "TestHost"
@ -50,7 +49,7 @@ func TestLogRotation(t *testing.T) {
rotatedFileName := fileName + ".rotated"
config := &types.AccessLog{FilePath: fileName, Format: CommonFormat}
logHandler, err := NewLogHandler(config)
logHandler, err := NewHandler(config)
if err != nil {
t.Fatalf("Error creating new log handler: %s", err)
}
@ -129,7 +128,7 @@ func TestLoggerCLF(t *testing.T) {
logData, err := ioutil.ReadFile(logFilePath)
require.NoError(t, err)
expectedLog := ` TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 1 "testFrontend" "http://127.0.0.1/testBackend" 1ms`
expectedLog := ` TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 1 "testRouter" "http://127.0.0.1/testService" 1ms`
assertValidLogData(t, expectedLog, logData)
}
@ -144,7 +143,7 @@ func TestAsyncLoggerCLF(t *testing.T) {
logData, err := ioutil.ReadFile(logFilePath)
require.NoError(t, err)
expectedLog := ` TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 1 "testFrontend" "http://127.0.0.1/testBackend" 1ms`
expectedLog := ` TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 1 "testRouter" "http://127.0.0.1/testService" 1ms`
assertValidLogData(t, expectedLog, logData)
}
@ -156,11 +155,11 @@ func assertString(exp string) func(t *testing.T, actual interface{}) {
}
}
func assertNotEqual(exp string) func(t *testing.T, actual interface{}) {
func assertNotEmpty() func(t *testing.T, actual interface{}) {
return func(t *testing.T, actual interface{}) {
t.Helper()
assert.NotEqual(t, exp, actual)
assert.NotEqual(t, "", actual)
}
}
@ -205,8 +204,8 @@ func TestLoggerJSON(t *testing.T) {
OriginStatus: assertFloat64(float64(testStatus)),
RequestRefererHeader: assertString(testReferer),
RequestUserAgentHeader: assertString(testUserAgent),
FrontendName: assertString(testFrontendName),
BackendURL: assertString(testBackendName),
RouterName: assertString(testRouterName),
ServiceURL: assertString(testServiceName),
ClientUsername: assertString(testUsername),
ClientHost: assertString(testHostname),
ClientPort: assertString(fmt.Sprintf("%d", testPort)),
@ -218,9 +217,9 @@ func TestLoggerJSON(t *testing.T) {
Duration: assertFloat64NotZero(),
Overhead: assertFloat64NotZero(),
RetryAttempts: assertFloat64(float64(testRetryAttempts)),
"time": assertNotEqual(""),
"StartLocal": assertNotEqual(""),
"StartUTC": assertNotEqual(""),
"time": assertNotEmpty(),
"StartLocal": assertNotEmpty(),
"StartUTC": assertNotEmpty(),
},
},
{
@ -235,7 +234,7 @@ func TestLoggerJSON(t *testing.T) {
expected: map[string]func(t *testing.T, value interface{}){
"level": assertString("info"),
"msg": assertString(""),
"time": assertNotEqual(""),
"time": assertNotEmpty(),
"downstream_Content-Type": assertString("text/plain; charset=utf-8"),
RequestRefererHeader: assertString(testReferer),
RequestUserAgentHeader: assertString(testUserAgent),
@ -256,7 +255,7 @@ func TestLoggerJSON(t *testing.T) {
expected: map[string]func(t *testing.T, value interface{}){
"level": assertString("info"),
"msg": assertString(""),
"time": assertNotEqual(""),
"time": assertNotEmpty(),
},
},
{
@ -274,7 +273,7 @@ func TestLoggerJSON(t *testing.T) {
expected: map[string]func(t *testing.T, value interface{}){
"level": assertString("info"),
"msg": assertString(""),
"time": assertNotEqual(""),
"time": assertNotEmpty(),
"downstream_Content-Type": assertString("REDACTED"),
RequestRefererHeader: assertString("REDACTED"),
RequestUserAgentHeader: assertString("REDACTED"),
@ -302,7 +301,7 @@ func TestLoggerJSON(t *testing.T) {
RequestHost: assertString(testHostname),
"level": assertString("info"),
"msg": assertString(""),
"time": assertNotEqual(""),
"time": assertNotEmpty(),
RequestRefererHeader: assertString(testReferer),
},
},
@ -349,7 +348,7 @@ func TestNewLogHandlerOutputStdout(t *testing.T) {
FilePath: "",
Format: CommonFormat,
},
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`,
expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testRouter" "http://127.0.0.1/testService" 1ms`,
},
{
desc: "default config with empty filters",
@ -358,7 +357,7 @@ func TestNewLogHandlerOutputStdout(t *testing.T) {
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`,
expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testRouter" "http://127.0.0.1/testService" 1ms`,
},
{
desc: "Status code filter not matching",
@ -380,7 +379,7 @@ func TestNewLogHandlerOutputStdout(t *testing.T) {
StatusCodes: []string{"123"},
},
},
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`,
expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testRouter" "http://127.0.0.1/testService" 1ms`,
},
{
desc: "Duration filter not matching",
@ -402,7 +401,7 @@ func TestNewLogHandlerOutputStdout(t *testing.T) {
MinDuration: parse.Duration(1 * time.Millisecond),
},
},
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`,
expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testRouter" "http://127.0.0.1/testService" 1ms`,
},
{
desc: "Retry attempts filter matching",
@ -413,7 +412,7 @@ func TestNewLogHandlerOutputStdout(t *testing.T) {
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`,
expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testRouter" "http://127.0.0.1/testService" 1ms`,
},
{
desc: "Default mode keep",
@ -424,7 +423,7 @@ func TestNewLogHandlerOutputStdout(t *testing.T) {
DefaultMode: "keep",
},
},
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`,
expectedLog: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testRouter" "http://127.0.0.1/testService" 1ms`,
},
{
desc: "Default mode keep with override",
@ -438,7 +437,7 @@ func TestNewLogHandlerOutputStdout(t *testing.T) {
},
},
},
expectedLog: `- - 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`,
expectedLog: `- - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 23 "testRouter" "http://127.0.0.1/testService" 1ms`,
},
{
desc: "Default mode drop",
@ -572,8 +571,8 @@ func assertValidLogData(t *testing.T, expected string, logData []byte) {
assert.Equal(t, resultExpected[RequestRefererHeader], result[RequestRefererHeader], formatErrMessage)
assert.Equal(t, resultExpected[RequestUserAgentHeader], result[RequestUserAgentHeader], formatErrMessage)
assert.Regexp(t, regexp.MustCompile("[0-9]*"), result[RequestCount], formatErrMessage)
assert.Equal(t, resultExpected[FrontendName], result[FrontendName], formatErrMessage)
assert.Equal(t, resultExpected[BackendURL], result[BackendURL], formatErrMessage)
assert.Equal(t, resultExpected[RouterName], result[RouterName], formatErrMessage)
assert.Equal(t, resultExpected[ServiceURL], result[ServiceURL], formatErrMessage)
assert.Regexp(t, regexp.MustCompile("[0-9]*ms"), result[Duration], formatErrMessage)
}
@ -599,7 +598,7 @@ func createTempDir(t *testing.T, prefix string) string {
}
func doLogging(t *testing.T, config *types.AccessLog) {
logger, err := NewLogHandler(config)
logger, err := NewHandler(config)
require.NoError(t, err)
defer logger.Close()
@ -618,6 +617,7 @@ func doLogging(t *testing.T, config *types.AccessLog) {
Method: testMethod,
RemoteAddr: fmt.Sprintf("%s:%d", testHostname, testPort),
URL: &url.URL{
User: url.UserPassword(testUsername, ""),
Path: testPath,
},
}
@ -627,18 +627,23 @@ func doLogging(t *testing.T, config *types.AccessLog) {
func logWriterTestHandlerFunc(rw http.ResponseWriter, r *http.Request) {
if _, err := rw.Write([]byte(testContent)); err != nil {
log.Error(err)
http.Error(rw, err.Error(), http.StatusInternalServerError)
return
}
logData := GetLogData(r)
if logData != nil {
logData.Core[RouterName] = testRouterName
logData.Core[ServiceURL] = testServiceName
logData.Core[OriginStatus] = testStatus
logData.Core[OriginContentSize] = testContentSize
logData.Core[RetryAttempts] = testRetryAttempts
logData.Core[StartUTC] = testStart.UTC()
logData.Core[StartLocal] = testStart.Local()
} else {
http.Error(rw, "LogData is nil", http.StatusInternalServerError)
return
}
rw.WriteHeader(testStatus)
logDataTable := GetLogDataTable(r)
logDataTable.Core[FrontendName] = testFrontendName
logDataTable.Core[BackendURL] = testBackendName
logDataTable.Core[OriginStatus] = testStatus
logDataTable.Core[OriginContentSize] = testContentSize
logDataTable.Core[RetryAttempts] = testRetryAttempts
logDataTable.Core[StartUTC] = testStart.UTC()
logDataTable.Core[StartLocal] = testStart.Local()
logDataTable.Core[ClientUsername] = testUsername
}

View file

@ -45,8 +45,8 @@ func ParseAccessLog(data string) (map[string]string, error) {
result[RequestRefererHeader] = submatch[9]
result[RequestUserAgentHeader] = submatch[10]
result[RequestCount] = submatch[11]
result[FrontendName] = submatch[12]
result[BackendURL] = submatch[13]
result[RouterName] = submatch[12]
result[ServiceURL] = submatch[13]
result[Duration] = submatch[14]
}

View file

@ -14,7 +14,7 @@ func TestParseAccessLog(t *testing.T) {
}{
{
desc: "full log",
value: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 1 "testFrontend" "http://127.0.0.1/testBackend" 1ms`,
value: `TestHost - TestUser [13/Apr/2016:07:14:19 -0700] "POST testpath HTTP/0.0" 123 12 "testReferer" "testUserAgent" 1 "testRouter" "http://127.0.0.1/testService" 1ms`,
expected: map[string]string{
ClientHost: "TestHost",
ClientUsername: "TestUser",
@ -27,14 +27,14 @@ func TestParseAccessLog(t *testing.T) {
RequestRefererHeader: `"testReferer"`,
RequestUserAgentHeader: `"testUserAgent"`,
RequestCount: "1",
FrontendName: `"testFrontend"`,
BackendURL: `"http://127.0.0.1/testBackend"`,
RouterName: `"testRouter"`,
ServiceURL: `"http://127.0.0.1/testService"`,
Duration: "1ms",
},
},
{
desc: "log with space",
value: `127.0.0.1 - - [09/Mar/2018:10:51:32 +0000] "GET / HTTP/1.1" 401 17 "-" "Go-http-client/1.1" 1 "testFrontend with space" - 0ms`,
value: `127.0.0.1 - - [09/Mar/2018:10:51:32 +0000] "GET / HTTP/1.1" 401 17 "-" "Go-http-client/1.1" 1 "testRouter with space" - 0ms`,
expected: map[string]string{
ClientHost: "127.0.0.1",
ClientUsername: "-",
@ -47,8 +47,8 @@ func TestParseAccessLog(t *testing.T) {
RequestRefererHeader: `"-"`,
RequestUserAgentHeader: `"Go-http-client/1.1"`,
RequestCount: "1",
FrontendName: `"testFrontend with space"`,
BackendURL: `-`,
RouterName: `"testRouter with space"`,
ServiceURL: `-`,
Duration: "0ms",
},
},

View file

@ -1,64 +0,0 @@
package accesslog
import (
"net/http"
"time"
"github.com/urfave/negroni"
"github.com/vulcand/oxy/utils"
)
// SaveBackend sends the backend name to the logger.
// These are always used with a corresponding SaveFrontend handler.
type SaveBackend struct {
next http.Handler
backendName string
}
// NewSaveBackend creates a SaveBackend handler.
func NewSaveBackend(next http.Handler, backendName string) http.Handler {
return &SaveBackend{next, backendName}
}
func (sb *SaveBackend) ServeHTTP(rw http.ResponseWriter, r *http.Request) {
serveSaveBackend(rw, r, sb.backendName, func(crw *captureResponseWriter) {
sb.next.ServeHTTP(crw, r)
})
}
// SaveNegroniBackend sends the backend name to the logger.
type SaveNegroniBackend struct {
next negroni.Handler
backendName string
}
// NewSaveNegroniBackend creates a SaveBackend handler.
func NewSaveNegroniBackend(next negroni.Handler, backendName string) negroni.Handler {
return &SaveNegroniBackend{next, backendName}
}
func (sb *SaveNegroniBackend) ServeHTTP(rw http.ResponseWriter, r *http.Request, next http.HandlerFunc) {
serveSaveBackend(rw, r, sb.backendName, func(crw *captureResponseWriter) {
sb.next.ServeHTTP(crw, r, next)
})
}
func serveSaveBackend(rw http.ResponseWriter, r *http.Request, backendName string, apply func(*captureResponseWriter)) {
table := GetLogDataTable(r)
table.Core[BackendName] = backendName
table.Core[BackendURL] = r.URL // note that this is *not* the original incoming URL
table.Core[BackendAddr] = r.URL.Host
crw := &captureResponseWriter{rw: rw}
start := time.Now().UTC()
apply(crw)
// use UTC to handle switchover of daylight saving correctly
table.Core[OriginDuration] = time.Now().UTC().Sub(start)
table.Core[OriginStatus] = crw.Status()
// make copy of headers so we can ensure there is no subsequent mutation during response processing
table.OriginResponse = make(http.Header)
utils.CopyHeaders(table.OriginResponse, crw.Header())
table.Core[OriginContentSize] = crw.Size()
}

View file

@ -1,51 +0,0 @@
package accesslog
import (
"net/http"
"strings"
"github.com/urfave/negroni"
)
// SaveFrontend sends the frontend name to the logger.
// These are sometimes used with a corresponding SaveBackend handler, but not always.
// For example, redirected requests don't reach a backend.
type SaveFrontend struct {
next http.Handler
frontendName string
}
// NewSaveFrontend creates a SaveFrontend handler.
func NewSaveFrontend(next http.Handler, frontendName string) http.Handler {
return &SaveFrontend{next, frontendName}
}
func (sf *SaveFrontend) ServeHTTP(rw http.ResponseWriter, r *http.Request) {
serveSaveFrontend(r, sf.frontendName, func() {
sf.next.ServeHTTP(rw, r)
})
}
// SaveNegroniFrontend sends the frontend name to the logger.
type SaveNegroniFrontend struct {
next negroni.Handler
frontendName string
}
// NewSaveNegroniFrontend creates a SaveNegroniFrontend handler.
func NewSaveNegroniFrontend(next negroni.Handler, frontendName string) negroni.Handler {
return &SaveNegroniFrontend{next, frontendName}
}
func (sf *SaveNegroniFrontend) ServeHTTP(rw http.ResponseWriter, r *http.Request, next http.HandlerFunc) {
serveSaveFrontend(r, sf.frontendName, func() {
sf.next.ServeHTTP(rw, r, next)
})
}
func serveSaveFrontend(r *http.Request, frontendName string, apply func()) {
table := GetLogDataTable(r)
table.Core[FrontendName] = strings.TrimPrefix(frontendName, "frontend-")
apply()
}

View file

@ -14,6 +14,8 @@ func (s *SaveRetries) Retried(req *http.Request, attempt int) {
attempt--
}
table := GetLogDataTable(req)
table.Core[RetryAttempts] = attempt
table := GetLogData(req)
if table != nil {
table.Core[RetryAttempts] = attempt
}
}

View file

@ -1,60 +0,0 @@
package accesslog
import (
"context"
"net/http"
"github.com/urfave/negroni"
)
const (
clientUsernameKey key = "ClientUsername"
)
// SaveUsername sends the Username name to the access logger.
type SaveUsername struct {
next http.Handler
}
// NewSaveUsername creates a SaveUsername handler.
func NewSaveUsername(next http.Handler) http.Handler {
return &SaveUsername{next}
}
func (sf *SaveUsername) ServeHTTP(rw http.ResponseWriter, r *http.Request) {
serveSaveUsername(r, func() {
sf.next.ServeHTTP(rw, r)
})
}
// SaveNegroniUsername adds the Username to the access logger data table.
type SaveNegroniUsername struct {
next negroni.Handler
}
// NewSaveNegroniUsername creates a SaveNegroniUsername handler.
func NewSaveNegroniUsername(next negroni.Handler) negroni.Handler {
return &SaveNegroniUsername{next}
}
func (sf *SaveNegroniUsername) ServeHTTP(rw http.ResponseWriter, r *http.Request, next http.HandlerFunc) {
serveSaveUsername(r, func() {
sf.next.ServeHTTP(rw, r, next)
})
}
func serveSaveUsername(r *http.Request, apply func()) {
table := GetLogDataTable(r)
username, ok := r.Context().Value(clientUsernameKey).(string)
if ok {
table.Core[ClientUsername] = username
}
apply()
}
// WithUserName adds a username to a requests' context
func WithUserName(req *http.Request, username string) *http.Request {
return req.WithContext(context.WithValue(req.Context(), clientUsernameKey, username))
}