Users: Add request logging

This patch adds new configuration options to the web.config.file which
makes it possible to enable logging of http requests.

The "request_log_config" struct takes two arguments, a "file" which
gets written to on request and "header_for_ip" which optionally
allows a user to override how the ip gets retrieved.

A log entry is formatted as json and currently contains the ip
of the request, if authentication was successful, the url path
and a timestamp

Signed-off-by: networkException <[email protected]>

Author: networkException

web/tls_config.go

@@ -20,7 +20,10 @@ import (
 	"io/ioutil"
 	"net"
 	"net/http"
+	"os"
 	"path/filepath"
+	"sync"
+	"time"
 
 	"github.com/go-kit/log"
 	"github.com/go-kit/log/level"
@@ -30,13 +33,18 @@ import (
 )
 
 var (
-	errNoTLSConfig = errors.New("TLS config is not present")
+	errNoTLSConfig  = errors.New("TLS config is not present")
+	timestampFormat = log.TimestampFormat(
+		func() time.Time { return time.Now().UTC() },
+		"2006-01-02T15:04:05.000Z07:00",
+	)
 )
 
 type Config struct {
-	TLSConfig  TLSStruct                     `yaml:"tls_server_config"`
-	HTTPConfig HTTPStruct                    `yaml:"http_server_config"`
-	Users      map[string]config_util.Secret `yaml:"basic_auth_users"`
+	TLSConfig        TLSStruct                     `yaml:"tls_server_config"`
+	HTTPConfig       HTTPStruct                    `yaml:"http_server_config"`
+	RequestLogConfig RequestLogStruct              `yaml:"request_log_config"`
+	Users            map[string]config_util.Secret `yaml:"basic_auth_users"`
 }
 
 type TLSStruct struct {
@@ -62,6 +70,15 @@ type HTTPStruct struct {
 	HTTP2 bool `yaml:"http2"`
 }
 
+type RequestLogStruct struct {
+	File        string `yaml:"file"`
+	HeaderForIp string `yaml:"header_for_ip"`
+}
+
+func (r *RequestLogStruct) SetDirectory(dir string) {
+	r.File = config_util.JoinDir(dir, r.File)
+}
+
 func getConfig(configPath string) (*Config, error) {
 	content, err := ioutil.ReadFile(configPath)
 	if err != nil {
@@ -73,10 +90,12 @@ func getConfig(configPath string) (*Config, error) {
 			MaxVersion:               tls.VersionTLS13,
 			PreferServerCipherSuites: true,
 		},
-		HTTPConfig: HTTPStruct{HTTP2: true},
+		HTTPConfig:       HTTPStruct{HTTP2: true},
+		RequestLogConfig: RequestLogStruct{File: "", HeaderForIp: ""},
 	}
 	err = yaml.UnmarshalStrict(content, c)
 	c.TLSConfig.SetDirectory(filepath.Dir(configPath))
+	c.RequestLogConfig.SetDirectory(filepath.Dir(configPath))
 	return c, err
 }
 
@@ -207,11 +226,33 @@ func Serve(l net.Listener, server *http.Server, tlsConfigPath string, logger log
 		return err
 	}
 
-	server.Handler = &userAuthRoundtrip{
-		tlsConfigPath: tlsConfigPath,
-		logger:        logger,
-		handler:       handler,
-		cache:         newCache(),
+	if c.RequestLogConfig.File != "" {
+		f, err := os.OpenFile(c.RequestLogConfig.File, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0666)
+		if err != nil {
+			return err
+		}
+
+		defer f.Close()
+
+		server.Handler = &userAuthRoundtrip{
+			tlsConfigPath:     tlsConfigPath,
+			logger:            logger,
+			handler:           handler,
+			cache:             newCache(),
+			requestLogger:     log.With(log.NewJSONLogger(f), "ts", timestampFormat),
+			requestLoggerLock: sync.RWMutex{},
+		}
+
+		level.Info(logger).Log("msg", "Request logging is enabled.", "file", c.RequestLogConfig.File, "headerForIp", c.RequestLogConfig.HeaderForIp)
+	} else {
+		server.Handler = &userAuthRoundtrip{
+			tlsConfigPath: tlsConfigPath,
+			logger:        logger,
+			handler:       handler,
+			cache:         newCache(),
+		}
+
+		level.Info(logger).Log("msg", "Request logging is disabled.")
 	}
 
 	config, err := ConfigToTLSConfig(&c.TLSConfig)

web/users.go

@@ -21,6 +21,7 @@ import (
 	"sync"
 
 	"github.com/go-kit/log"
+	"github.com/go-kit/log/level"
 	"golang.org/x/crypto/bcrypt"
 )
 
@@ -41,10 +42,12 @@ func validateUsers(configPath string) error {
 }
 
 type userAuthRoundtrip struct {
-	tlsConfigPath string
-	handler       http.Handler
-	logger        log.Logger
-	cache         *cache
+	tlsConfigPath     string
+	handler           http.Handler
+	logger            log.Logger
+	requestLogger     log.Logger
+	requestLoggerLock sync.RWMutex
+	cache             *cache
 	// bcryptMtx is there to ensure that bcrypt.CompareHashAndPassword is run
 	// only once in parallel as this is CPU intensive.
 	bcryptMtx sync.Mutex
@@ -89,10 +92,31 @@ func (u *userAuthRoundtrip) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 
 		if authOk && validUser {
 			u.handler.ServeHTTP(w, r)
+			logRequest(u, r, c, true)
 			return
 		}
 	}
 
 	w.Header().Set("WWW-Authenticate", "Basic")
 	http.Error(w, http.StatusText(http.StatusUnauthorized), http.StatusUnauthorized)
+
+	logRequest(u, r, c, false)
+}
+
+func logRequest(u *userAuthRoundtrip, r *http.Request, c *Config, authorized bool) {
+	u.requestLoggerLock.RLock()
+
+	if l := u.requestLogger; l != nil {
+		var ip = r.RemoteAddr
+
+		if c.RequestLogConfig.HeaderForIp != "" {
+			ip = r.Header.Get(c.RequestLogConfig.HeaderForIp)
+		}
+
+		if err := l.Log("path", r.URL.Path, "authorized", authorized, "ip", ip); err != nil {
+			level.Error(u.logger).Log("msg", "can't log query", "err", err)
+		}
+	}
+
+	u.requestLoggerLock.RUnlock()
 }