From 0f9608d91583c8f92a519cf026408f42a5c39046 Mon Sep 17 00:00:00 2001 From: Leigh McCulloch Date: Fri, 21 Feb 2020 16:04:48 -0800 Subject: [PATCH 1/4] support/http: support specifying a logger --- .../recoverysigner/internal/serve/serve.go | 4 +- exp/services/webauth/internal/serve/serve.go | 4 +- support/http/logging_middleware.go | 12 ++++++ support/http/mux.go | 38 +++++++++++++++++-- 4 files changed, 53 insertions(+), 5 deletions(-) diff --git a/exp/services/recoverysigner/internal/serve/serve.go b/exp/services/recoverysigner/internal/serve/serve.go index fadc0248ce..3693c572c4 100644 --- a/exp/services/recoverysigner/internal/serve/serve.go +++ b/exp/services/recoverysigner/internal/serve/serve.go @@ -107,7 +107,9 @@ func getHandlerDeps(opts Options) (handlerDeps, error) { } func handler(deps handlerDeps) http.Handler { - mux := supporthttp.NewAPIMux() + mux := supporthttp.NewAPIMux( + supporthttp.WithMuxOptionLogger(deps.Logger), + ) mux.NotFound(errorHandler{Error: notFound}.ServeHTTP) mux.MethodNotAllowed(errorHandler{Error: methodNotAllowed}.ServeHTTP) diff --git a/exp/services/webauth/internal/serve/serve.go b/exp/services/webauth/internal/serve/serve.go index fdbcfe2d49..eb21062af7 100644 --- a/exp/services/webauth/internal/serve/serve.go +++ b/exp/services/webauth/internal/serve/serve.go @@ -66,7 +66,9 @@ func handler(opts Options) (http.Handler, error) { } horizonClient.SetHorizonTimeOut(uint(horizonTimeout / time.Second)) - mux := supporthttp.NewAPIMux() + mux := supporthttp.NewAPIMux( + supporthttp.WithMuxOptionLogger(opts.Logger), + ) mux.NotFound(errorHandler{Error: notFound}.ServeHTTP) mux.MethodNotAllowed(errorHandler{Error: methodNotAllowed}.ServeHTTP) diff --git a/support/http/logging_middleware.go b/support/http/logging_middleware.go index 8ec3048a46..dc4ff9592f 100644 --- a/support/http/logging_middleware.go +++ b/support/http/logging_middleware.go @@ -10,6 +10,18 @@ import ( "github.com/stellar/go/support/log" ) +// SetLogger is a middleware that sets a logger on the context. +func SetLoggerMiddleware(l *log.Entry) func(stdhttp.Handler) stdhttp.Handler { + return func(next stdhttp.Handler) stdhttp.Handler { + return stdhttp.HandlerFunc(func(w stdhttp.ResponseWriter, r *stdhttp.Request) { + ctx := r.Context() + ctx = log.Set(ctx, l) + r = r.WithContext(ctx) + next.ServeHTTP(w, r) + }) + } +} + // LoggingMiddleware is a middleware that logs requests to the logger. func LoggingMiddleware(next stdhttp.Handler) stdhttp.Handler { return stdhttp.HandlerFunc(func(w stdhttp.ResponseWriter, r *stdhttp.Request) { diff --git a/support/http/mux.go b/support/http/mux.go index d84eb013db..be85176e92 100644 --- a/support/http/mux.go +++ b/support/http/mux.go @@ -4,15 +4,21 @@ import ( "github.com/go-chi/chi" "github.com/go-chi/chi/middleware" "github.com/rs/cors" + "github.com/stellar/go/support/log" ) // NewMux returns a new server mux configured with the common defaults used across all // stellar services. -func NewMux() *chi.Mux { +func NewMux(options ...MuxOption) *chi.Mux { + muxOptions := NewMuxOptions(options...) + mux := chi.NewMux() mux.Use(middleware.RequestID) mux.Use(middleware.Recoverer) + if muxOptions.Logger != nil { + mux.Use(SetLoggerMiddleware(muxOptions.Logger)) + } mux.Use(LoggingMiddleware) return mux @@ -20,8 +26,8 @@ func NewMux() *chi.Mux { // NewAPIMux returns a new server mux configured with the common defaults used for a web API in // stellar. -func NewAPIMux() *chi.Mux { - mux := NewMux() +func NewAPIMux(options ...MuxOption) *chi.Mux { + mux := NewMux(options...) c := cors.New(cors.Options{ AllowedOrigins: []string{"*"}, @@ -32,3 +38,29 @@ func NewAPIMux() *chi.Mux { mux.Use(c.Handler) return mux } + +// MuxOptions is a set of options that can be optionally set when calling +// NewMux or NewAPIMux. +type MuxOptions struct { + Logger *log.Entry +} + +// NewMuxOptions creates a MuxOptions from a set of MuxOption. +func NewMuxOptions(options ...MuxOption) MuxOptions { + mo := MuxOptions{} + for _, o := range options { + mo = o(mo) + } + return mo +} + +// MuxOption is a function that sets mux options. +type MuxOption func(options MuxOptions) MuxOptions + +// WithMuxOptionLogger sets a logger when instantiating a mux. +func WithMuxOptionLogger(l *log.Entry) func(MuxOptions) MuxOptions { + return func(options MuxOptions) MuxOptions { + options.Logger = l + return options + } +} From 86a733ec376d56dd3985bfa2ebfd4967ab053009 Mon Sep 17 00:00:00 2001 From: Leigh McCulloch Date: Fri, 21 Feb 2020 16:20:07 -0800 Subject: [PATCH 2/4] support/http: support specifying a logger, v2 --- .../recoverysigner/internal/serve/serve.go | 4 +- exp/services/webauth/internal/serve/serve.go | 4 +- services/bridge/main.go | 3 +- services/compliance/main.go | 5 ++- services/federation/main.go | 2 +- services/friendbot/main.go | 2 +- support/http/logging_middleware_test.go | 35 +++++++++++++++++ support/http/mux.go | 38 +++---------------- 8 files changed, 49 insertions(+), 44 deletions(-) diff --git a/exp/services/recoverysigner/internal/serve/serve.go b/exp/services/recoverysigner/internal/serve/serve.go index 3693c572c4..4527d0fbb5 100644 --- a/exp/services/recoverysigner/internal/serve/serve.go +++ b/exp/services/recoverysigner/internal/serve/serve.go @@ -107,9 +107,7 @@ func getHandlerDeps(opts Options) (handlerDeps, error) { } func handler(deps handlerDeps) http.Handler { - mux := supporthttp.NewAPIMux( - supporthttp.WithMuxOptionLogger(deps.Logger), - ) + mux := supporthttp.NewAPIMux(deps.Logger) mux.NotFound(errorHandler{Error: notFound}.ServeHTTP) mux.MethodNotAllowed(errorHandler{Error: methodNotAllowed}.ServeHTTP) diff --git a/exp/services/webauth/internal/serve/serve.go b/exp/services/webauth/internal/serve/serve.go index eb21062af7..935fac94b2 100644 --- a/exp/services/webauth/internal/serve/serve.go +++ b/exp/services/webauth/internal/serve/serve.go @@ -66,9 +66,7 @@ func handler(opts Options) (http.Handler, error) { } horizonClient.SetHorizonTimeOut(uint(horizonTimeout / time.Second)) - mux := supporthttp.NewAPIMux( - supporthttp.WithMuxOptionLogger(opts.Logger), - ) + mux := supporthttp.NewAPIMux(opts.Logger) mux.NotFound(errorHandler{Error: notFound}.ServeHTTP) mux.MethodNotAllowed(errorHandler{Error: methodNotAllowed}.ServeHTTP) diff --git a/services/bridge/main.go b/services/bridge/main.go index fca9e70a71..e36f262d33 100644 --- a/services/bridge/main.go +++ b/services/bridge/main.go @@ -23,6 +23,7 @@ import ( "github.com/stellar/go/support/db/schema" "github.com/stellar/go/support/errors" supportHttp "github.com/stellar/go/support/http" + supportLog "github.com/stellar/go/support/log" ) var app *App @@ -231,7 +232,7 @@ func NewApp(config config.Config, migrateFlag bool, versionFlag bool, version st // Serve starts the server func (a *App) Serve() { - mux := supportHttp.NewAPIMux() + mux := supportHttp.NewAPIMux(supportLog.DefaultLogger) // Middlewares headers := make(http.Header) diff --git a/services/compliance/main.go b/services/compliance/main.go index 0ea181a16e..1cf2edc662 100644 --- a/services/compliance/main.go +++ b/services/compliance/main.go @@ -22,6 +22,7 @@ import ( "github.com/stellar/go/support/db/schema" "github.com/stellar/go/support/errors" supportHttp "github.com/stellar/go/support/http" + supportLog "github.com/stellar/go/support/log" ) var app *App @@ -170,7 +171,7 @@ func NewApp(config config.Config, migrateFlag bool, versionFlag bool, version st // Serve starts the server func (a *App) Serve() { // External endpoints - external := supportHttp.NewAPIMux() + external := supportHttp.NewAPIMux(supportLog.DefaultLogger) // Middlewares headers := http.Header{} @@ -195,7 +196,7 @@ func (a *App) Serve() { }() // Internal endpoints - internal := supportHttp.NewAPIMux() + internal := supportHttp.NewAPIMux(supportLog.DefaultLogger) internal.Use(supportHttp.StripTrailingSlashMiddleware("/admin")) internal.Use(supportHttp.HeadersMiddleware(headers, "/admin/")) diff --git a/services/federation/main.go b/services/federation/main.go index 8f163d1e54..8898001a8b 100644 --- a/services/federation/main.go +++ b/services/federation/main.go @@ -126,7 +126,7 @@ func initDriver(cfg Config) (federation.Driver, error) { } func initMux(driver federation.Driver) *chi.Mux { - mux := http.NewAPIMux() + mux := http.NewAPIMux(log.DefaultLogger) fed := &federation.Handler{ Driver: driver, diff --git a/services/friendbot/main.go b/services/friendbot/main.go index 07cbef527c..d63bc09c7c 100644 --- a/services/friendbot/main.go +++ b/services/friendbot/main.go @@ -82,7 +82,7 @@ func run(cmd *cobra.Command, args []string) { } func initRouter(fb *internal.Bot) *chi.Mux { - mux := http.NewAPIMux() + mux := http.NewAPIMux(log.DefaultLogger) handler := &internal.FriendbotHandler{Friendbot: fb} mux.Get("/", handler.Handle) diff --git a/support/http/logging_middleware_test.go b/support/http/logging_middleware_test.go index 88578bea10..19647eec26 100644 --- a/support/http/logging_middleware_test.go +++ b/support/http/logging_middleware_test.go @@ -43,3 +43,38 @@ func TestHTTPMiddleware(t *testing.T) { assert.NotEmpty(t, line.Data["path"]) } } + +func TestHTTPMiddlewareWithLoggerSet(t *testing.T) { + logger := log.New() + done := logger.StartTest(log.InfoLevel) + mux := chi.NewMux() + + mux.Use(middleware.RequestID) + mux.Use(SetLoggerMiddleware(logger)) + mux.Use(LoggingMiddleware) + + mux.Get("/", stdhttp.HandlerFunc(func(w stdhttp.ResponseWriter, r *stdhttp.Request) { + })) + mux.Handle("/not_found", stdhttp.NotFoundHandler()) + + src := httptest.NewServer(t, mux) + src.GET("/").Expect().Status(stdhttp.StatusOK) + src.GET("/not_found").Expect().Status(stdhttp.StatusNotFound) + + // get the log buffer and ensure it has both the start and end log lines for + // each request + logged := done() + if assert.Len(t, logged, 4, "unexpected log line count") { + assert.Equal(t, "starting request", logged[0].Message) + assert.Equal(t, "starting request", logged[2].Message) + assert.Equal(t, "finished request", logged[1].Message) + assert.Equal(t, "finished request", logged[3].Message) + } + + for _, line := range logged { + assert.Equal(t, "http", line.Data["subsys"]) + assert.Equal(t, "GET", line.Data["method"]) + assert.NotEmpty(t, line.Data["req"]) + assert.NotEmpty(t, line.Data["path"]) + } +} diff --git a/support/http/mux.go b/support/http/mux.go index be85176e92..379d64a4a9 100644 --- a/support/http/mux.go +++ b/support/http/mux.go @@ -9,15 +9,13 @@ import ( // NewMux returns a new server mux configured with the common defaults used across all // stellar services. -func NewMux(options ...MuxOption) *chi.Mux { - muxOptions := NewMuxOptions(options...) - +func NewMux(l *log.Entry) *chi.Mux { mux := chi.NewMux() mux.Use(middleware.RequestID) mux.Use(middleware.Recoverer) - if muxOptions.Logger != nil { - mux.Use(SetLoggerMiddleware(muxOptions.Logger)) + if l != nil { + mux.Use(SetLoggerMiddleware(l)) } mux.Use(LoggingMiddleware) @@ -26,8 +24,8 @@ func NewMux(options ...MuxOption) *chi.Mux { // NewAPIMux returns a new server mux configured with the common defaults used for a web API in // stellar. -func NewAPIMux(options ...MuxOption) *chi.Mux { - mux := NewMux(options...) +func NewAPIMux(l *log.Entry) *chi.Mux { + mux := NewMux(l) c := cors.New(cors.Options{ AllowedOrigins: []string{"*"}, @@ -38,29 +36,3 @@ func NewAPIMux(options ...MuxOption) *chi.Mux { mux.Use(c.Handler) return mux } - -// MuxOptions is a set of options that can be optionally set when calling -// NewMux or NewAPIMux. -type MuxOptions struct { - Logger *log.Entry -} - -// NewMuxOptions creates a MuxOptions from a set of MuxOption. -func NewMuxOptions(options ...MuxOption) MuxOptions { - mo := MuxOptions{} - for _, o := range options { - mo = o(mo) - } - return mo -} - -// MuxOption is a function that sets mux options. -type MuxOption func(options MuxOptions) MuxOptions - -// WithMuxOptionLogger sets a logger when instantiating a mux. -func WithMuxOptionLogger(l *log.Entry) func(MuxOptions) MuxOptions { - return func(options MuxOptions) MuxOptions { - options.Logger = l - return options - } -} From af1a18289be3cc83875f739a82f39eaf02f74d42 Mon Sep 17 00:00:00 2001 From: Leigh McCulloch Date: Fri, 21 Feb 2020 16:46:20 -0800 Subject: [PATCH 3/4] Fix the example tests --- support/render/health/example_test.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/support/render/health/example_test.go b/support/render/health/example_test.go index 94979e5c55..53d4bfa7b1 100644 --- a/support/render/health/example_test.go +++ b/support/render/health/example_test.go @@ -12,7 +12,7 @@ import ( ) func ExampleResponse() { - mux := supporthttp.NewAPIMux() + mux := supporthttp.NewAPIMux(nil) mux.Get("/health", func(w http.ResponseWriter, r *http.Request) { healthCheckResult := false @@ -44,7 +44,7 @@ func ExampleResponse() { } func ExampleHandler() { - mux := supporthttp.NewAPIMux() + mux := supporthttp.NewAPIMux(nil) mux.Get("/health", health.PassHandler{}.ServeHTTP) From c789584fff2dfcb501decccbc827e55bf2123a9a Mon Sep 17 00:00:00 2001 From: Leigh McCulloch Date: Fri, 21 Feb 2020 17:11:08 -0800 Subject: [PATCH 4/4] feedback from Alex: simplify the logging so that it is not optional --- support/http/mux.go | 4 +--- support/render/health/example_test.go | 5 +++-- 2 files changed, 4 insertions(+), 5 deletions(-) diff --git a/support/http/mux.go b/support/http/mux.go index 379d64a4a9..ca041d3797 100644 --- a/support/http/mux.go +++ b/support/http/mux.go @@ -14,9 +14,7 @@ func NewMux(l *log.Entry) *chi.Mux { mux.Use(middleware.RequestID) mux.Use(middleware.Recoverer) - if l != nil { - mux.Use(SetLoggerMiddleware(l)) - } + mux.Use(SetLoggerMiddleware(l)) mux.Use(LoggingMiddleware) return mux diff --git a/support/render/health/example_test.go b/support/render/health/example_test.go index 53d4bfa7b1..3ff0cc136b 100644 --- a/support/render/health/example_test.go +++ b/support/render/health/example_test.go @@ -7,12 +7,13 @@ import ( "net/http/httptest" supporthttp "github.com/stellar/go/support/http" + "github.com/stellar/go/support/log" "github.com/stellar/go/support/render/health" "github.com/stellar/go/support/render/httpjson" ) func ExampleResponse() { - mux := supporthttp.NewAPIMux(nil) + mux := supporthttp.NewAPIMux(log.DefaultLogger) mux.Get("/health", func(w http.ResponseWriter, r *http.Request) { healthCheckResult := false @@ -44,7 +45,7 @@ func ExampleResponse() { } func ExampleHandler() { - mux := supporthttp.NewAPIMux(nil) + mux := supporthttp.NewAPIMux(log.DefaultLogger) mux.Get("/health", health.PassHandler{}.ServeHTTP)