Do not give responsewriter or its headers to asynchronous logging goroutine

Co-authored-by: Julien Salleyron <julien.salleyron@gmail.com>

pkg/middlewares/accesslog/logdata.go

@@ -116,7 +116,18 @@ type CoreLogData map[string]interface{}
 // LogData is the data captured by the middleware so that it can be logged.
 type LogData struct {
 	Core               CoreLogData
-	Request            http.Header
+	Request            request
 	OriginResponse     http.Header
-	DownstreamResponse http.Header
+	DownstreamResponse downstreamResponse
+}
+
+type downstreamResponse struct {
+	headers http.Header
+	status  int
+	size    int64
+}
+
+type request struct {
+	headers http.Header
+	count   int64
 }

pkg/middlewares/accesslog/logger.go

@@ -47,8 +47,6 @@ func (n noopCloser) Close() error {
 
 type handlerParams struct {
 	logDataTable *LogData
-	crr          *captureRequestReader
-	crw          *captureResponseWriter
 }
 
 // Handler will write each request and its response to the access log.
@@ -122,7 +120,7 @@ func NewHandler(config *types.AccessLog) (*Handler, error) {
 		go func() {
 			defer logHandler.wg.Done()
 			for handlerParams := range logHandler.logHandlerChan {
-				logHandler.logTheRoundTrip(handlerParams.logDataTable, handlerParams.crr, handlerParams.crw)
+				logHandler.logTheRoundTrip(handlerParams.logDataTable)
 			}
 		}()
 	}
@@ -162,7 +160,12 @@ func (h *Handler) ServeHTTP(rw http.ResponseWriter, req *http.Request, next http
 		StartLocal: now.Local(),
 	}
 
-	logDataTable := &LogData{Core: core, Request: req.Header}
+	logDataTable := &LogData{
+		Core: core,
+		Request: request{
+			headers: req.Header,
+		},
+	}
 
 	reqWithDataTable := req.WithContext(context.WithValue(req.Context(), DataTableKey, logDataTable))
 
@@ -205,16 +208,21 @@ func (h *Handler) ServeHTTP(rw http.ResponseWriter, req *http.Request, next http
 		core[ClientUsername] = usernameIfPresent(reqWithDataTable.URL)
 	}
 
-	logDataTable.DownstreamResponse = crw.Header()
+	logDataTable.DownstreamResponse = downstreamResponse{
+		headers: crw.Header().Clone(),
+		status:  crw.Status(),
+		size:    crw.Size(),
+	}
+	if crr != nil {
+		logDataTable.Request.count = crr.count
+	}
 
 	if h.config.BufferingSize > 0 {
 		h.logHandlerChan <- handlerParams{
 			logDataTable: logDataTable,
-			crr:          crr,
-			crw:          crw,
 		}
 	} else {
-		h.logTheRoundTrip(logDataTable, crr, crw)
+		h.logTheRoundTrip(logDataTable)
 	}
 }
 
@@ -264,7 +272,7 @@ func usernameIfPresent(theURL *url.URL) string {
 }
 
 // Logging handler to log frontend name, backend name, and elapsed time.
-func (h *Handler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestReader, crw *captureResponseWriter) {
+func (h *Handler) logTheRoundTrip(logDataTable *LogData) {
 	core := logDataTable.Core
 
 	retryAttempts, ok := core[RetryAttempts].(int)
@@ -272,23 +280,22 @@ func (h *Handler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestRead
 		retryAttempts = 0
 	}
 	core[RetryAttempts] = retryAttempts
+	core[RequestContentSize] = logDataTable.Request.count
 
-	if crr != nil {
+	status := logDataTable.DownstreamResponse.status
-		core[RequestContentSize] = crr.count
+	core[DownstreamStatus] = status
-	}
-
-	core[DownstreamStatus] = crw.Status()
 
 	// 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 h.keepAccessLog(crw.Status(), retryAttempts, totalDuration) {
+	if h.keepAccessLog(status, retryAttempts, totalDuration) {
-		core[DownstreamContentSize] = crw.Size()
+		size := logDataTable.DownstreamResponse.size
+		core[DownstreamContentSize] = size
 		if original, ok := core[OriginContentSize]; ok {
 			o64 := original.(int64)
-			if crw.Size() != o64 && crw.Size() != 0 {
+			if size != o64 && size != 0 {
-				core[GzipRatio] = float64(o64) / float64(crw.Size())
+				core[GzipRatio] = float64(o64) / float64(size)
 			}
 		}
 
@@ -305,9 +312,9 @@ func (h *Handler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestRead
 			}
 		}
 
-		h.redactHeaders(logDataTable.Request, fields, "request_")
+		h.redactHeaders(logDataTable.Request.headers, fields, "request_")
 		h.redactHeaders(logDataTable.OriginResponse, fields, "origin_")
-		h.redactHeaders(logDataTable.DownstreamResponse, fields, "downstream_")
+		h.redactHeaders(logDataTable.DownstreamResponse.headers, fields, "downstream_")
 
 		h.mu.Lock()
 		defer h.mu.Unlock()

pkg/middlewares/accesslog/logger_test.go

@@ -192,6 +192,7 @@ func TestLoggerJSON(t *testing.T) {
 				Format:   JSONFormat,
 			},
 			expected: map[string]func(t *testing.T, value interface{}){
+				RequestContentSize:        assertFloat64(0),
 				RequestHost:               assertString(testHostname),
 				RequestAddr:               assertString(testHostname),
 				RequestMethod:             assertString(testMethod),