From 4059ee454818a025d38393b09cdc45234592956f Mon Sep 17 00:00:00 2001 From: George Blue Date: Wed, 7 Feb 2024 18:10:52 +0000 Subject: [PATCH] feat: ensure public API consistently uses slog.Logger Previously some of the public API had been altered to take the (internal) Blog logger. This is not correct, so the public API should now consistely take a *slog.Logger, and a Blog logger now implements the slog.Handler interface so can easily be converted to a slog.Logger. --- domain/apiresponses/failure_responses.go | 10 ++--- domain/apiresponses/failure_responses_test.go | 19 +++----- failure_response_test.go | 19 +++----- handlers/bind.go | 3 +- handlers/catalog.go | 3 +- handlers/deprovision.go | 3 +- handlers/get_binding.go | 3 +- handlers/get_instance.go | 3 +- handlers/last_binding_operation.go | 2 +- handlers/last_operation.go | 2 +- handlers/provision.go | 2 +- handlers/unbind.go | 3 +- handlers/update.go | 3 +- internal/blog/blog.go | 44 +++++++++++++++++++ middlewares/api_version_header.go | 2 +- 15 files changed, 79 insertions(+), 42 deletions(-) diff --git a/domain/apiresponses/failure_responses.go b/domain/apiresponses/failure_responses.go index 1a3cc7c3..6be2669f 100644 --- a/domain/apiresponses/failure_responses.go +++ b/domain/apiresponses/failure_responses.go @@ -1,11 +1,9 @@ package apiresponses import ( - "errors" "fmt" + "log/slog" "net/http" - - "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) // FailureResponse can be returned from any of the `ServiceBroker` interface methods @@ -44,9 +42,11 @@ func (f *FailureResponse) ErrorResponse() interface{} { } } -func (f *FailureResponse) ValidatedStatusCode(logger blog.Blog) int { +func (f *FailureResponse) ValidatedStatusCode(logger *slog.Logger) int { if f.statusCode < 400 || 600 <= f.statusCode { - logger.Error("validating-status-code", errors.New("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) + if logger != nil { + logger.Error("validating-status-code", slog.String("error", "Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) + } return http.StatusInternalServerError } return f.statusCode diff --git a/domain/apiresponses/failure_responses_test.go b/domain/apiresponses/failure_responses_test.go index 66e56f81..ff89664f 100644 --- a/domain/apiresponses/failure_responses_test.go +++ b/domain/apiresponses/failure_responses_test.go @@ -9,16 +9,9 @@ import ( . "github.com/onsi/gomega" "github.com/onsi/gomega/gbytes" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" - "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) var _ = Describe("FailureResponse", func() { - var fakeLogger blog.Blog - - BeforeEach(func() { - fakeLogger = blog.New(slog.New(slog.NewJSONHandler(GinkgoWriter, nil))) - }) - Describe("ErrorResponse", func() { It("returns a ErrorResponse containing the error message", func() { failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) @@ -53,7 +46,7 @@ var _ = Describe("FailureResponse", func() { newError := failureResponse.AppendErrorMessage("and some more details") Expect(newError.Error()).To(Equal("my error message and some more details")) - Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) errorResponse, typeCast := newError.ErrorResponse().(apiresponses.ErrorResponse) @@ -69,7 +62,7 @@ var _ = Describe("FailureResponse", func() { newError := failureResponse.AppendErrorMessage("and some more details") Expect(newError.Error()).To(Equal("my error message and some more details")) - Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) Expect(newError.ErrorResponse()).To(Equal(failureResponse.ErrorResponse())) }) @@ -78,23 +71,23 @@ var _ = Describe("FailureResponse", func() { Describe("ValidatedStatusCode", func() { It("returns the status code that was passed in", func() { failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) - Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) }) It("when error key is provided it returns the status code that was passed in", func() { failureResponse := apiresponses.NewFailureResponseBuilder(errors.New("my error message"), http.StatusForbidden, "log-key").WithErrorKey("error key").Build() - Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) }) Context("when the status code is invalid", func() { It("returns 500", func() { failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), 600, "log-key")) - Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusInternalServerError)) + Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusInternalServerError)) }) It("logs that the status has been changed", func() { log := gbytes.NewBuffer() - logger := blog.New(slog.New(slog.NewJSONHandler(log, nil))) + logger := slog.New(slog.NewJSONHandler(log, nil)) failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), 600, "log-key")) failureResponse.ValidatedStatusCode(logger) Expect(log).To(gbytes.Say("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) diff --git a/failure_response_test.go b/failure_response_test.go index e3cc163f..5ec9cd28 100644 --- a/failure_response_test.go +++ b/failure_response_test.go @@ -25,16 +25,9 @@ import ( "github.com/onsi/gomega/gbytes" "github.com/pivotal-cf/brokerapi/v10" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" - "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) var _ = Describe("FailureResponse", func() { - var fakeLogger blog.Blog - - BeforeEach(func() { - fakeLogger = blog.New(slog.New(slog.NewJSONHandler(GinkgoWriter, nil))) - }) - Describe("ErrorResponse", func() { It("returns a ErrorResponse containing the error message", func() { failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) @@ -69,7 +62,7 @@ var _ = Describe("FailureResponse", func() { newError := failureResponse.AppendErrorMessage("and some more details") Expect(newError.Error()).To(Equal("my error message and some more details")) - Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) errorResponse, typeCast := newError.ErrorResponse().(brokerapi.ErrorResponse) @@ -85,7 +78,7 @@ var _ = Describe("FailureResponse", func() { newError := failureResponse.AppendErrorMessage("and some more details") Expect(newError.Error()).To(Equal("my error message and some more details")) - Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) Expect(newError.ErrorResponse()).To(Equal(failureResponse.ErrorResponse())) }) @@ -94,23 +87,23 @@ var _ = Describe("FailureResponse", func() { Describe("ValidatedStatusCode", func() { It("returns the status code that was passed in", func() { failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) - Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) }) It("when error key is provided it returns the status code that was passed in", func() { failureResponse := brokerapi.NewFailureResponseBuilder(errors.New("my error message"), http.StatusForbidden, "log-key").WithErrorKey("error key").Build() - Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) }) Context("when the status code is invalid", func() { It("returns 500", func() { failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), 600, "log-key")) - Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusInternalServerError)) + Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusInternalServerError)) }) It("logs that the status has been changed", func() { log := gbytes.NewBuffer() - logger := blog.New(slog.New(slog.NewJSONHandler(log, nil))) + logger := slog.New(slog.NewJSONHandler(log, nil)) failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), 600, "log-key")) failureResponse.ValidatedStatusCode(logger) Expect(log).To(gbytes.Say("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) diff --git a/handlers/bind.go b/handlers/bind.go index b8a900bf..81a7c517 100644 --- a/handlers/bind.go +++ b/handlers/bind.go @@ -3,6 +3,7 @@ package handlers import ( "encoding/json" "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/internal/blog" @@ -61,7 +62,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - statusCode := err.ValidatedStatusCode(logger) + statusCode := err.ValidatedStatusCode(slog.New(logger)) errorResponse := err.ErrorResponse() if err == apiresponses.ErrInstanceDoesNotExist { // work around ErrInstanceDoesNotExist having different pre-refactor behaviour to other actions diff --git a/handlers/catalog.go b/handlers/catalog.go index fc0917d7..c3ea93aa 100644 --- a/handlers/catalog.go +++ b/handlers/catalog.go @@ -2,6 +2,7 @@ package handlers import ( "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" @@ -19,7 +20,7 @@ func (h *APIHandler) Catalog(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/deprovision.go b/handlers/deprovision.go index a56c505d..8e3ca092 100644 --- a/handlers/deprovision.go +++ b/handlers/deprovision.go @@ -2,6 +2,7 @@ package handlers import ( "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/internal/blog" @@ -50,7 +51,7 @@ func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/get_binding.go b/handlers/get_binding.go index 77342f01..59ecc026 100644 --- a/handlers/get_binding.go +++ b/handlers/get_binding.go @@ -3,6 +3,7 @@ package handlers import ( "errors" "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/internal/blog" @@ -43,7 +44,7 @@ func (h APIHandler) GetBinding(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/get_instance.go b/handlers/get_instance.go index 64b608a9..d389a8c3 100644 --- a/handlers/get_instance.go +++ b/handlers/get_instance.go @@ -3,6 +3,7 @@ package handlers import ( "errors" "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/internal/blog" @@ -42,7 +43,7 @@ func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/last_binding_operation.go b/handlers/last_binding_operation.go index 38fcc25a..832265cb 100644 --- a/handlers/last_binding_operation.go +++ b/handlers/last_binding_operation.go @@ -45,7 +45,7 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/last_operation.go b/handlers/last_operation.go index 7abc4e64..2cfe759e 100644 --- a/handlers/last_operation.go +++ b/handlers/last_operation.go @@ -33,7 +33,7 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/provision.go b/handlers/provision.go index d610cb01..f33afa7f 100644 --- a/handlers/provision.go +++ b/handlers/provision.go @@ -98,7 +98,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/unbind.go b/handlers/unbind.go index 0a2b3022..40fc7a03 100644 --- a/handlers/unbind.go +++ b/handlers/unbind.go @@ -2,6 +2,7 @@ package handlers import ( "fmt" + "log/slog" "net/http" "github.com/go-chi/chi/v5" @@ -48,7 +49,7 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/update.go b/handlers/update.go index b1ccbf6f..cb7548fa 100644 --- a/handlers/update.go +++ b/handlers/update.go @@ -3,6 +3,7 @@ package handlers import ( "encoding/json" "fmt" + "log/slog" "net/http" "strconv" @@ -46,7 +47,7 @@ func (h APIHandler) Update(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/internal/blog/blog.go b/internal/blog/blog.go index 758a4064..ae8421e2 100644 --- a/internal/blog/blog.go +++ b/internal/blog/blog.go @@ -3,6 +3,9 @@ // and it relied on some idiosyncrasies of that logger that are not found in the (subsequently written) // Go standard library log/slog logger. This package is a wrapper around log/slog that adds back the // idiosyncrasies of lager, minimizes boilerplate code, and keeps the behavior as similar as possible. +// It also implements the slog.Handler interface so that it can easily be converted into a slog.Logger. +// This is useful when calling public APIs (such as FailureResponse.ValidatedStatusCode) which take a +// slog.Logger as an input, and because they are public cannot take a Blog as in input. package blog import ( @@ -28,6 +31,8 @@ func New(logger *slog.Logger) Blog { return Blog{logger: logger} } +// Session emulates a Lager logger session. It returns a new logger that will always log the +// attributes, prefix, and data from the context. func (b Blog) Session(ctx context.Context, prefix string, attr ...any) Blog { for _, key := range []middlewares.ContextKey{middlewares.CorrelationIDKey, middlewares.RequestIdentityKey} { if value := ctx.Value(key); value != nil { @@ -41,23 +46,62 @@ func (b Blog) Session(ctx context.Context, prefix string, attr ...any) Blog { } } +// Error logs an error. It takes an error type as a convenience, which is different to slog.Logger.Error() func (b Blog) Error(message string, err error, attr ...any) { b.logger.Error(join(b.prefix, message), append([]any{slog.Any(errorKey, err)}, attr...)...) } +// Info logs information. It behaves a lot file slog.Logger.Info() func (b Blog) Info(message string, attr ...any) { b.logger.Info(join(b.prefix, message), attr...) } +// With returns a logger that always logs the specified attributes func (b Blog) With(attr ...any) Blog { b.logger = b.logger.With(attr...) return b } +// Enabled is required implement the slog.Handler interface +func (b Blog) Enabled(context.Context, slog.Level) bool { + return true +} + +// WithAttrs is required implement the slog.Handler interface +func (b Blog) WithAttrs(attrs []slog.Attr) slog.Handler { + var attributes []any + for _, a := range attrs { + attributes = append(attributes, a) + } + return b.With(attributes...) +} + +// WithGroup is required implement the slog.Handler interface +func (b Blog) WithGroup(string) slog.Handler { + return b +} + +func (b Blog) Handle(_ context.Context, record slog.Record) error { + switch record.Level { + case slog.LevelDebug: + b.logger.Debug(join(b.prefix, record.Message)) + case slog.LevelInfo: + b.logger.Info(join(b.prefix, record.Message)) + case slog.LevelWarn: + b.logger.Warn(join(b.prefix, record.Message)) + default: + b.logger.Error(join(b.prefix, record.Message)) + } + + return nil +} + +// InstanceID creates an attribute from an instance ID func InstanceID(instanceID string) slog.Attr { return slog.String(instanceIDLogKey, instanceID) } +// BindingID creates an attribute from an binding ID func BindingID(bindingID string) slog.Attr { return slog.String(bindingIDLogKey, bindingID) } diff --git a/middlewares/api_version_header.go b/middlewares/api_version_header.go index 4032e123..08df623d 100644 --- a/middlewares/api_version_header.go +++ b/middlewares/api_version_header.go @@ -30,7 +30,7 @@ const ( ) type APIVersionMiddleware struct { - Logger interface{ Error(string, ...any) } + Logger *slog.Logger } type ErrorResponse struct {