From 88486bb0d560694779a0bedfbd4826f2e3c395fb Mon Sep 17 00:00:00 2001 From: Nikita Zinkevich Date: Mon, 5 Aug 2024 09:27:38 +0300 Subject: [PATCH] [#369] HTTP status code logging Signed-off-by: Nikita Zinkevich --- api/middleware/log_http.go | 116 +++++++++++++++++++------------------ 1 file changed, 61 insertions(+), 55 deletions(-) diff --git a/api/middleware/log_http.go b/api/middleware/log_http.go index 5621b43..7c367c5 100644 --- a/api/middleware/log_http.go +++ b/api/middleware/log_http.go @@ -7,6 +7,7 @@ import ( "io" "net/http" "net/url" + "sync" "git.frostfs.info/TrueCloudLab/frostfs-s3-gw/internal/logs" "git.frostfs.info/TrueCloudLab/frostfs-s3-gw/playback/utils" @@ -15,18 +16,30 @@ import ( "gopkg.in/natefinch/lumberjack.v2" ) -type LogHTTPConfig struct { - Enabled bool - MaxBody int64 - MaxLogSize int - OutputPath string - UseGzip bool -} - -type fileLogger struct { - *zap.Logger - logRoller *lumberjack.Logger -} +type ( + LogHTTPConfig struct { + Enabled bool + MaxBody int64 + MaxLogSize int + OutputPath string + UseGzip bool + } + fileLogger struct { + *zap.Logger + logRoller *lumberjack.Logger + } + // Implementation of zap.Sink for using lumberjack. + lumberjackSink struct { + *lumberjack.Logger + } + // responseReadWriter helps read http response body. + responseReadWriter struct { + sync.Once + http.ResponseWriter + response *bytes.Buffer + statusCode int + } +) const ( payloadLabel = "payload" @@ -75,11 +88,6 @@ func (f *fileLogger) registerOutputSink(conf *LogHTTPConfig) error { return nil } -// Implementation of zap.Sink for using lumberjack. -type lumberjackSink struct { - *lumberjack.Logger -} - func (lumberjackSink) Sync() error { return nil } @@ -101,17 +109,18 @@ func ReloadFileLogger(conf *LogHTTPConfig) error { return nil } -// responseReadWriter helps read http response body. -type responseReadWriter struct { - http.ResponseWriter - response *bytes.Buffer -} - func (ww *responseReadWriter) Write(data []byte) (int, error) { ww.response.Write(data) return ww.ResponseWriter.Write(data) } +func (ww *responseReadWriter) WriteHeader(code int) { + ww.Do(func() { + ww.statusCode = code + ww.ResponseWriter.WriteHeader(code) + }) +} + func (ww *responseReadWriter) Flush() { if f, ok := ww.ResponseWriter.(http.Flusher); ok { f.Flush() @@ -137,43 +146,36 @@ func LogHTTP(l *zap.Logger, config *LogHTTPConfig) Func { return } - httplog := filelog.getHTTPLogger(r) - httplog.withFieldIfExist("query", r.URL.Query()) - httplog.withFieldIfExist("headers", r.Header) + httplog := filelog.getHTTPLogger(r). + withFieldIfExist("query", r.URL.Query()). + withFieldIfExist("headers", r.Header) - payload, err := getBody(r.Body) - if err != nil { - l.Error(logs.FailedToGetHTTPBody, - zap.Error(err), - zap.String("body type", payloadLabel)) - return - } + payload := getBody(r.Body, l) r.Body = io.NopCloser(bytes.NewReader(payload)) + payloadReader := io.LimitReader(bytes.NewReader(payload), config.MaxBody) + httplog = httplog.withProcessedBody(payloadLabel, payloadReader, l) + respBuf := &bytes.Buffer{} wr := &responseReadWriter{ResponseWriter: w, response: respBuf} h.ServeHTTP(wr, r) - payloadReader := io.LimitReader(bytes.NewReader(payload), config.MaxBody) - httplog, err = httplog.withProcessedBody(payloadLabel, payloadReader) - if err != nil { - l.Error(logs.FailedToProcessHTTPBody, - zap.Error(err), - zap.String("body type", payloadLabel)) - } respReader := io.LimitReader(respBuf, config.MaxBody) - httplog, err = httplog.withProcessedBody(responseLabel, respReader) - if err != nil { - l.Error(logs.FailedToProcessHTTPBody, - zap.Error(err), - zap.String("body type", responseLabel)) - } + httplog = httplog.withProcessedBody(responseLabel, respReader, l) + httplog = httplog.with(zap.Int("status", wr.statusCode)) httplog.Info(logs.LogHTTP) }) } } +func (f *fileLogger) with(fields ...zap.Field) *fileLogger { + return &fileLogger{ + Logger: f.Logger.With(fields...), + logRoller: f.logRoller, + } +} + func (f *fileLogger) getHTTPLogger(r *http.Request) *fileLogger { return &fileLogger{ Logger: f.Logger.With( @@ -186,14 +188,16 @@ func (f *fileLogger) getHTTPLogger(r *http.Request) *fileLogger { } } -func (f *fileLogger) withProcessedBody(label string, bodyReader io.Reader) (*fileLogger, error) { +func (f *fileLogger) withProcessedBody(label string, bodyReader io.Reader, l *zap.Logger) *fileLogger { resp, err := ProcessBody(bodyReader) if err != nil { - return f, err + l.Error(logs.FailedToProcessHTTPBody, + zap.Error(err), + zap.String("body type", payloadLabel)) + return f } - f.Logger = f.Logger.With(zap.ByteString(label, resp)) - return f, nil + return f.with(zap.ByteString(label, resp)) } // newLoggerConfig creates new zap.Config with disabled base fields. @@ -209,15 +213,17 @@ func (f *fileLogger) newLoggerConfig() zap.Config { return c } -// getBody reads http.Body and returns its io.Reader. -func getBody(httpBody io.ReadCloser) ([]byte, error) { +func getBody(httpBody io.ReadCloser, l *zap.Logger) []byte { defer httpBody.Close() body, err := io.ReadAll(httpBody) if err != nil { - return nil, err + l.Error(logs.FailedToGetHTTPBody, + zap.Error(err), + zap.String("body type", payloadLabel)) + return nil } - return body, nil + return body } // ProcessBody reads body and base64 encode it if it's not XML. @@ -239,7 +245,7 @@ func ProcessBody(bodyReader io.Reader) ([]byte, error) { // withFieldIfExist checks whether data is not empty and attach it to log output. func (f *fileLogger) withFieldIfExist(label string, data map[string][]string) *fileLogger { if len(data) != 0 { - f.Logger = f.Logger.With(zap.Any(label, data)) + return f.with(zap.Any(label, data)) } return f }