From be13e09ee6d1f8a1ef9f54d2f56113b10db3c074 Mon Sep 17 00:00:00 2001 From: Rein Krul Date: Tue, 17 Sep 2024 12:15:31 +0200 Subject: [PATCH] Enable access logs, if configured --- api/proxy.go | 6 +++--- config.go | 31 +++++++++++-------------------- go.mod | 1 + go.sum | 6 ++++++ main.go | 49 ++++++++++++++++++++++++++++++++++++++++++++----- 5 files changed, 65 insertions(+), 28 deletions(-) diff --git a/api/proxy.go b/api/proxy.go index 4859f58..8118a01 100644 --- a/api/proxy.go +++ b/api/proxy.go @@ -3,7 +3,7 @@ package api import ( "github.com/labstack/echo/v4" "github.com/labstack/echo/v4/middleware" - "log" + "github.com/rs/zerolog" "net/http" "net/url" "regexp" @@ -64,7 +64,7 @@ var allowedProxyRoutes = []proxyRoute{ // ConfigureProxy configures the proxy middleware for the given Nuts node address. // It allows the web application to call a curated list of endpoints on the Nuts node. -func ConfigureProxy(e *echo.Echo, nodeAddress *url.URL) { +func ConfigureProxy(logger zerolog.Logger, e *echo.Echo, nodeAddress *url.URL) { e.Use(middleware.ProxyWithConfig(middleware.ProxyConfig{ Balancer: middleware.NewRoundRobinBalancer([]*middleware.ProxyTarget{ { @@ -84,7 +84,7 @@ func ConfigureProxy(e *echo.Echo, nodeAddress *url.URL) { proxyURL = "/" + strings.TrimLeft(proxyURL, "/") for _, route := range allowedProxyRoutes { if c.Request().Method == route.method && route.compiledPath.MatchString(proxyURL) { - log.Printf("proxying %s %s", c.Request().Method, proxyURL) + logger.Info().Msgf("proxying %s %s", c.Request().Method, proxyURL) return false } } diff --git a/config.go b/config.go index fa30fdc..6e73fa7 100644 --- a/config.go +++ b/config.go @@ -10,7 +10,6 @@ import ( "errors" "fmt" "golang.org/x/crypto/ssh" - "io" "log" "os" "strings" @@ -34,13 +33,15 @@ func defaultConfig() Config { Node: Node{ Address: "http://localhost:8081", }, + AccessLogs: true, } } type Config struct { - HTTPPort int `koanf:"port"` - Node Node `koanf:"node"` - apiKey crypto.Signer + HTTPPort int `koanf:"port"` + Node Node `koanf:"node"` + AccessLogs bool `koanf:"accesslogs"` + apiKey crypto.Signer } type Node struct { @@ -66,19 +67,9 @@ func generateSessionKey() (*ecdsa.PrivateKey, error) { return key, nil } -func (c Config) Print(writer io.Writer) error { - if _, err := fmt.Fprintln(writer, "========== CONFIG: =========="); err != nil { - return err - } - var pr Config = c - data, _ := json.MarshalIndent(pr, "", " ") - if _, err := fmt.Println(writer, string(data)); err != nil { - return err - } - if _, err := fmt.Fprintln(writer, "========= END CONFIG ========="); err != nil { - return err - } - return nil +func (c Config) Print() { + data, _ := json.Marshal(c) + logger.Info().Msgf("Config: %s", string(data)) } func loadConfig() Config { @@ -90,12 +81,12 @@ func loadConfig() Config { configFilePath := resolveConfigFile(flagset) // Check if the file exists if _, err := os.Stat(configFilePath); err == nil { - log.Printf("Loading config from file: %s", configFilePath) + logger.Info().Msgf("Loading config from file: %s", configFilePath) if err := k.Load(file.Provider(configFilePath), yaml.Parser()); err != nil { - log.Fatalf("error while loading config from file: %v", err) + logger.Fatal().Msgf("error while loading config from file: %v", err) } } else { - log.Printf("Using default config because no file was found at: %s", configFilePath) + logger.Info().Msgf("Using default config because no file was found at: %s", configFilePath) } // load env flags, can't return error diff --git a/go.mod b/go.mod index 3bf2e15..fa96299 100644 --- a/go.mod +++ b/go.mod @@ -37,6 +37,7 @@ require ( github.com/multiformats/go-base36 v0.1.0 // indirect github.com/multiformats/go-multibase v0.2.0 // indirect github.com/pkg/errors v0.9.1 // indirect + github.com/rs/zerolog v1.33.0 // indirect github.com/segmentio/asm v1.2.0 // indirect github.com/shengdoushi/base58 v1.0.0 // indirect github.com/valyala/bytebufferpool v1.0.0 // indirect diff --git a/go.sum b/go.sum index 71f3b0b..3216a0b 100644 --- a/go.sum +++ b/go.sum @@ -36,6 +36,7 @@ github.com/cncf/udpa/go v0.0.0-20191209042840-269d4d468f6f/go.mod h1:M8M6+tZqaGX github.com/cncf/udpa/go v0.0.0-20201120205902-5459f2c99403/go.mod h1:WmhPx2Nbnhtbo57+VJT5O0JRkEi1Wbu0z5j0R8u5Hbk= github.com/coreos/go-semver v0.3.0/go.mod h1:nnelYz7RCh+5ahJtPPxZlU+153eP4D4r3EedlOD2RNk= github.com/coreos/go-systemd/v22 v22.3.2/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= +github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= @@ -195,6 +196,7 @@ github.com/mattn/go-isatty v0.0.10/go.mod h1:qgIWMr58cqv1PHHyhnkY9lrL7etaEgOFcME github.com/mattn/go-isatty v0.0.11/go.mod h1:PhnuNfih5lzO57/f3n+odYbM4JtupLOxQOAqxQCu2WE= github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU= github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= +github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY= github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0= @@ -266,6 +268,9 @@ github.com/prometheus/procfs v0.1.3/go.mod h1:lV6e/gmhEcM9IjHGsFOCxxuZ+z1YqCvr4O github.com/prometheus/procfs v0.6.0/go.mod h1:cz+aTbrPOrUb4q7XlbU9ygM+/jj0fzG6c1xBZuNvfVA= github.com/rhnvrm/simples3 v0.6.1/go.mod h1:Y+3vYm2V7Y4VijFoJHHTrja6OgPrJ2cBti8dPGkC3sA= github.com/rogpeppe/fastuuid v1.2.0/go.mod h1:jVj6XXZzXRy/MSR5jhDC/2q6DgLz+nrA6LYCDYWNEvQ= +github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.33.0 h1:1cU2KZkvPxNyfgEmhHAz/1A9Bz+llsdYzklWFzgp0r8= +github.com/rs/zerolog v1.33.0/go.mod h1:/7mN4D5sKwJLZQ2b/znpjC3/GQWY/xaDXUM0kKWRHss= github.com/ryanuber/columnize v0.0.0-20160712163229-9b3edd62028f/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts= github.com/ryanuber/columnize v2.1.0+incompatible/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts= github.com/ryanuber/go-glob v1.0.0/go.mod h1:807d1WSdnB0XRJzKNil9Om6lcp/3a0v4qIHxIXzX/Yc= @@ -403,6 +408,7 @@ golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBc golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.8.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.15.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= golang.org/x/sys v0.16.0 h1:xWw16ngr6ZMtmxDyKyIgsE93KNKz5HKmMa3b8ALHidU= golang.org/x/sys v0.16.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= diff --git a/main.go b/main.go index aa7ff0f..e33f1a5 100644 --- a/main.go +++ b/main.go @@ -8,6 +8,7 @@ import ( "errors" "fmt" "github.com/google/uuid" + "github.com/labstack/echo/v4/middleware" "github.com/lestrrat-go/jwx/jwk" "github.com/lestrrat-go/jwx/jwt" "github.com/nuts-foundation/nuts-admin/discovery" @@ -15,6 +16,7 @@ import ( "github.com/nuts-foundation/nuts-admin/issuer" "github.com/nuts-foundation/nuts-admin/nuts/vcr" "github.com/nuts-foundation/nuts-admin/nuts/vdr" + "github.com/rs/zerolog" "io/fs" "log" "net/http" @@ -32,13 +34,14 @@ const assetPath = "web/dist" //go:embed web/dist/* var embeddedFiles embed.FS +var logger zerolog.Logger + func getFileSystem(useFS bool) http.FileSystem { if useFS { - log.Print("using live mode") + logger.Info().Msg("using live mode") return http.FS(os.DirFS(assetPath)) } - - log.Print("using embed mode") + logger.Debug().Msg("using embed mode") fsys, err := fs.Sub(embeddedFiles, assetPath) if err != nil { panic(err) @@ -48,12 +51,20 @@ func getFileSystem(useFS bool) http.FileSystem { } func main() { + logger = zerolog.New(log.Writer()).With().Timestamp().Logger() config := loadConfig() - config.Print(log.Writer()) + config.Print() e := echo.New() e.HideBanner = true e.HTTPErrorHandler = httpErrorHandler + e.HideBanner = true + e.HidePort = true + if config.AccessLogs { + e.Use(accessLoggerMiddleware(func(c echo.Context) bool { + return c.Request().URL.Path == "/status" + }, logger)) + } nodeAddress, err := url.Parse(config.Node.Address) if err != nil { @@ -92,7 +103,7 @@ func main() { } api.RegisterHandlers(e, apiWrapper) - api.ConfigureProxy(e, nodeAddress) + api.ConfigureProxy(logger, e, nodeAddress) // Setup asset serving: // Check if we use live mode from the file system or using embedded files @@ -216,3 +227,31 @@ func ecAlgUsingPublicKey(key ecdsa.PublicKey) (alg jwa.SignatureAlgorithm, err e } return } + +// accessLoggerMiddleware returns middleware that logs metadata of HTTP requests. +// Should be added as the outer middleware to catch all errors and potential status rewrites +func accessLoggerMiddleware(skipper middleware.Skipper, logger zerolog.Logger) echo.MiddlewareFunc { + return middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{ + Skipper: skipper, + LogURI: true, + LogStatus: true, + LogMethod: true, + LogRemoteIP: true, + LogError: true, + LogValuesFunc: func(c echo.Context, values middleware.RequestLoggerValues) error { + event := logger.Info().Fields(map[string]interface{}{ + "remote_ip": values.RemoteIP, + "method": values.Method, + "uri": values.URI, + "status": values.Status, + }) + if logger.GetLevel() >= zerolog.DebugLevel { + event.Fields(map[string]interface{}{ + "headers": values.Headers, + }) + } + event.Msg("HTTP request") + return nil + }, + }) +}