[#369] Enhanced http requests logging

Signed-off-by: Nikita Zinkevich <n.zinkevich@yadro.com>

api/middleware/log_http.go

@@ -0,0 +1,61 @@
+package middleware
+
+import (
+	"io"
+	"net/http"
+
+	"git.frostfs.info/TrueCloudLab/frostfs-s3-gw/internal/logs"
+	"go.uber.org/zap"
+)
+
+type LogHTTPSettings struct {
+	Enabled bool
+	MaxBody int64
+}
+
+// LogHTTP logs http parameters from s3 request.
+func LogHTTP(l *zap.Logger, settings LogHTTPSettings) Func {
+	return func(h http.Handler) http.Handler {
+		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+			if !settings.Enabled {
+				h.ServeHTTP(w, r)
+				return
+			}
+			var httplog = l.With(
+				zap.String("from", r.RemoteAddr),
+				zap.String("URI", r.RequestURI),
+				zap.String("method", r.Method),
+			)
+
+			httplog = withFieldIfExist(httplog, "query", r.URL.Query())
+			httplog = withFieldIfExist(httplog, "headers", r.Header)
+			if r.ContentLength != 0 && r.ContentLength <= settings.MaxBody {
+				var err error
+				httplog, err = withBody(httplog, r)
+				if err != nil {
+					l.Error("read body error")
+				}
+			}
+			httplog.Info(logs.RequestHTTP)
+			h.ServeHTTP(w, r)
+		})
+	}
+}
+
+func withBody(httplog *zap.Logger, r *http.Request) (*zap.Logger, error) {
+	var body = make([]byte, r.ContentLength)
+	_, err := r.Body.Read(body)
+	if err != nil && err != io.EOF {
+		return nil, err
+	}
+	httplog = httplog.With(zap.String("body", string(body)))
+
+	return httplog, nil
+}
+
+func withFieldIfExist(log *zap.Logger, label string, data map[string][]string) *zap.Logger {
+	if len(data) != 0 {
+		log = log.With(zap.Any(label, data))
+	}
+	return log
+}

api/router.go

@@ -110,6 +110,7 @@ type Config struct {
 	Handler  Handler
 	Center   s3middleware.Center
 	Log      *zap.Logger
+	LogHTTP  s3middleware.LogHTTPSettings
 	Metrics  *metrics.AppMetrics
 
 	MiddlewareSettings Settings
@@ -127,6 +128,7 @@ type Config struct {
 func NewRouter(cfg Config) *chi.Mux {
 	api := chi.NewRouter()
 	api.Use(
+		s3middleware.LogHTTP(cfg.Log, cfg.LogHTTP),
 		s3middleware.Request(cfg.Log, cfg.MiddlewareSettings),
 		middleware.ThrottleWithOpts(cfg.Throttle),
 		middleware.Recoverer,

cmd/s3-gw/app.go

@@ -86,6 +86,8 @@ type (
 
 	appSettings struct {
 		logLevel            zap.AtomicLevel
+		httpLoggingEnabled  bool
+		maxHTTPLogBody      int64
 		maxClient           maxClientsConfig
 		defaultMaxAge       int
 		reconnectInterval   time.Duration
@@ -220,6 +222,8 @@ func newAppSettings(log *Logger, v *viper.Viper) *appSettings {
 		defaultMaxAge:       fetchDefaultMaxAge(v, log.logger),
 		reconnectInterval:   fetchReconnectInterval(v),
 		frostfsidValidation: v.GetBool(cfgFrostfsIDValidationEnabled),
+		httpLoggingEnabled:  v.GetBool(cfgLoggerRequestEnabled),
+		maxHTTPLogBody:      v.GetInt64(cfgLoggerRequestMaxBody),
 	}
 
 	settings.resolveZoneList = v.GetStringSlice(cfgResolveBucketAllow)
@@ -758,6 +762,10 @@ func (a *App) Serve(ctx context.Context) {
 		Handler: a.api,
 		Center:  a.ctr,
 		Log:     a.log,
+		LogHTTP: s3middleware.LogHTTPSettings{
+			Enabled: a.settings.httpLoggingEnabled,
+			MaxBody: a.settings.maxHTTPLogBody,
+		},
 		Metrics: a.metrics,
 
 		MiddlewareSettings: a.settings,

cmd/s3-gw/app_settings.go

@@ -79,6 +79,9 @@ const ( // Settings.
 	cfgLoggerLevel       = "logger.level"
 	cfgLoggerDestination = "logger.destination"
 
+	cfgLoggerRequestEnabled = "http_logging.enabled"
+	cfgLoggerRequestMaxBody = "http_logging.max_body"
+
 	// Wallet.
 	cfgWalletPath       = "wallet.path"
 	cfgWalletAddress    = "wallet.address"
@@ -764,6 +767,10 @@ func newSettings() *viper.Viper {
 	v.SetDefault(cfgLoggerLevel, "debug")
 	v.SetDefault(cfgLoggerDestination, "stdout")
 
+	// http logger
+	v.SetDefault(cfgLoggerRequestEnabled, false)
+	v.SetDefault(cfgLoggerRequestMaxBody, 1024)
+
 	// pool:
 	v.SetDefault(cfgPoolErrorThreshold, defaultPoolErrorThreshold)
 	v.SetDefault(cfgStreamTimeout, defaultStreamTimeout)

config/config.yaml

@@ -56,6 +56,12 @@ logger:
   level: debug
   destination: stdout
 
+# log http request data (URI, headers, query, etc)
+http_logging:
+  enabled: false
+  # max body size to log
+  max_body: 1024
+  
 # RPC endpoint and order of resolving of bucket names
 rpc_endpoint: http://morph-chain.frostfs.devenv:30333
 resolve_order:

internal/logs/logs.go

@@ -99,6 +99,8 @@ const (
 	FailedToPassAuthentication                           = "failed to pass authentication"                                                                     // Error in ../../api/middleware/auth.go
 	FailedToResolveCID                                   = "failed to resolve CID"                                                                             // Debug in ../../api/middleware/metrics.go
 	RequestStart                                         = "request start"                                                                                     // Info in ../../api/middleware/reqinfo.go
+
+	RequestHTTP                                    = "http request"
 	FailedToUnescapeObjectName                           = "failed to unescape object name"                                                                    // Warn in ../../api/middleware/reqinfo.go
 	InvalidDefaultMaxAge                                 = "invalid defaultMaxAge"                                                                             // Fatal in ../../cmd/s3-gw/app_settings.go
 	CantShutDownService                                  = "can't shut down service"                                                                           // Panic in ../../cmd/s3-gw/service.go