Make accesslogs.logTheRoundTrip async to get lost performance

middlewares/accesslog/logger.go

@@ -31,6 +31,12 @@ const (
 	JSONFormat = "json"
 )
 
+type logHandlerParams struct {
+	logDataTable *LogData
+	crr          *captureRequestReader
+	crw          *captureResponseWriter
+}
+
 // LogHandler will write each request and its response to the access log.
 type LogHandler struct {
 	config         *types.AccessLog
@@ -38,6 +44,8 @@ type LogHandler struct {
 	file           *os.File
 	mu             sync.Mutex
 	httpCodeRanges types.HTTPCodeRanges
+	logHandlerChan chan logHandlerParams
+	wg             sync.WaitGroup
 }
 
 // NewLogHandler creates a new LogHandler
@@ -50,6 +58,7 @@ func NewLogHandler(config *types.AccessLog) (*LogHandler, error) {
 		}
 		file = f
 	}
+	logHandlerChan := make(chan logHandlerParams, config.BufferingSize)
 
 	var formatter logrus.Formatter
 
@@ -70,9 +79,10 @@ func NewLogHandler(config *types.AccessLog) (*LogHandler, error) {
 	}
 
 	logHandler := &LogHandler{
-		config: config,
-		logger: logger,
-		file:   file,
+		config:         config,
+		logger:         logger,
+		file:           file,
+		logHandlerChan: logHandlerChan,
 	}
 
 	if config.Filters != nil {
@@ -83,6 +93,16 @@ func NewLogHandler(config *types.AccessLog) (*LogHandler, error) {
 		}
 	}
 
+	if config.BufferingSize > 0 {
+		logHandler.wg.Add(1)
+		go func() {
+			defer logHandler.wg.Done()
+			for handlerParams := range logHandler.logHandlerChan {
+				logHandler.logTheRoundTrip(handlerParams.logDataTable, handlerParams.crr, handlerParams.crw)
+			}
+		}()
+	}
+
 	return logHandler, nil
 }
 
@@ -162,11 +182,22 @@ func (l *LogHandler) ServeHTTP(rw http.ResponseWriter, req *http.Request, next h
 	core[ClientUsername] = usernameIfPresent(reqWithDataTable.URL)
 
 	logDataTable.DownstreamResponse = crw.Header()
-	l.logTheRoundTrip(logDataTable, crr, crw)
+
+	if l.config.BufferingSize > 0 {
+		l.logHandlerChan <- logHandlerParams{
+			logDataTable: logDataTable,
+			crr:          crr,
+			crw:          crw,
+		}
+	} else {
+		l.logTheRoundTrip(logDataTable, crr, crw)
+	}
 }
 
-// Close closes the Logger (i.e. the file etc).
+// 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()
 }
 

middlewares/accesslog/logger_test.go

@@ -130,6 +130,21 @@ func TestLoggerCLF(t *testing.T) {
 	assertValidLogData(t, expectedLog, logData)
 }
 
+func TestAsyncLoggerCLF(t *testing.T) {
+	tmpDir := createTempDir(t, CommonFormat)
+	defer os.RemoveAll(tmpDir)
+
+	logFilePath := filepath.Join(tmpDir, logFileNameSuffix)
+	config := &types.AccessLog{FilePath: logFilePath, Format: CommonFormat, BufferingSize: 1024}
+	doLogging(t, config)
+
+	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`
+	assertValidLogData(t, expectedLog, logData)
+}
+
 func assertString(exp string) func(t *testing.T, actual interface{}) {
 	return func(t *testing.T, actual interface{}) {
 		t.Helper()