diff --git a/api_options.go b/api_options.go index becf23af..362127ef 100644 --- a/api_options.go +++ b/api_options.go @@ -30,17 +30,13 @@ type middlewareFunc func(http.Handler) http.Handler type config struct { router chi.Router customRouter bool - logger *slog.Logger additionalMiddleware []middlewareFunc } func NewWithOptions(serviceBroker domain.ServiceBroker, logger *slog.Logger, opts ...Option) http.Handler { - cfg := config{ - router: chi.NewRouter(), - logger: logger, - } + cfg := config{router: chi.NewRouter()} - WithOptions(append(opts, withDefaultMiddleware())...)(&cfg) + WithOptions(append(opts, withDefaultMiddleware(logger))...)(&cfg) attachRoutes(cfg.router, serviceBroker, logger) return cfg.router @@ -91,11 +87,11 @@ func WithEncodedPath() Option { return func(*config) {} } -func withDefaultMiddleware() Option { +func withDefaultMiddleware(logger *slog.Logger) Option { return func(c *config) { if !c.customRouter { defaults := []middlewareFunc{ - middlewares.APIVersionMiddleware{Logger: c.logger}.ValidateAPIVersionHdr, + middlewares.APIVersionMiddleware{Logger: logger}.ValidateAPIVersionHdr, middlewares.AddCorrelationIDToContext, middlewares.AddOriginatingIdentityToContext, middlewares.AddInfoLocationToContext, diff --git a/domain/apiresponses/failure_responses.go b/domain/apiresponses/failure_responses.go index b657defc..1a3cc7c3 100644 --- a/domain/apiresponses/failure_responses.go +++ b/domain/apiresponses/failure_responses.go @@ -4,6 +4,8 @@ import ( "errors" "fmt" "net/http" + + "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) // FailureResponse can be returned from any of the `ServiceBroker` interface methods @@ -42,11 +44,9 @@ func (f *FailureResponse) ErrorResponse() interface{} { } } -func (f *FailureResponse) ValidatedStatusCode(logger interface{ Error(string, error) }) int { +func (f *FailureResponse) ValidatedStatusCode(logger blog.Blog) int { if f.statusCode < 400 || 600 <= f.statusCode { - if logger != nil { - logger.Error("validating-status-code", errors.New("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) - } + logger.Error("validating-status-code", errors.New("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 edc6b3fc..66e56f81 100644 --- a/domain/apiresponses/failure_responses_test.go +++ b/domain/apiresponses/failure_responses_test.go @@ -1,7 +1,6 @@ package apiresponses_test import ( - "context" "errors" "log/slog" "net/http" @@ -14,6 +13,12 @@ import ( ) 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")) @@ -48,7 +53,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(nil)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) errorResponse, typeCast := newError.ErrorResponse().(apiresponses.ErrorResponse) @@ -64,7 +69,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(nil)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) Expect(newError.ErrorResponse()).To(Equal(failureResponse.ErrorResponse())) }) @@ -73,23 +78,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(nil)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).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(nil)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).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(nil)).To(Equal(http.StatusInternalServerError)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusInternalServerError)) }) It("logs that the status has been changed", func() { log := gbytes.NewBuffer() - logger := blog.New(context.TODO(), slog.New(slog.NewJSONHandler(log, nil)), "prefix") + logger := blog.New(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 4c2ee8f1..e3cc163f 100644 --- a/failure_response_test.go +++ b/failure_response_test.go @@ -16,7 +16,6 @@ package brokerapi_test import ( - "context" "errors" "log/slog" "net/http" @@ -30,6 +29,12 @@ import ( ) 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")) @@ -64,7 +69,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(nil)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) errorResponse, typeCast := newError.ErrorResponse().(brokerapi.ErrorResponse) @@ -80,7 +85,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(nil)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) Expect(newError.ErrorResponse()).To(Equal(failureResponse.ErrorResponse())) }) @@ -89,23 +94,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(nil)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).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(nil)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).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(nil)).To(Equal(http.StatusInternalServerError)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusInternalServerError)) }) It("logs that the status has been changed", func() { log := gbytes.NewBuffer() - logger := blog.New(context.TODO(), slog.New(slog.NewJSONHandler(log, nil)), "prefix") + logger := blog.New(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/api_handler.go b/handlers/api_handler.go index fc39f30b..4bfbdec7 100644 --- a/handlers/api_handler.go +++ b/handlers/api_handler.go @@ -7,6 +7,8 @@ import ( "log/slog" "net/http" + "github.com/pivotal-cf/brokerapi/v10/internal/blog" + "github.com/pivotal-cf/brokerapi/v10/domain" ) @@ -26,11 +28,11 @@ var ( type APIHandler struct { serviceBroker domain.ServiceBroker - logger *slog.Logger + logger blog.Blog } func NewApiHandler(broker domain.ServiceBroker, logger *slog.Logger) APIHandler { - return APIHandler{broker, logger} + return APIHandler{serviceBroker: broker, logger: blog.New(logger)} } func (h APIHandler) respond(w http.ResponseWriter, status int, requestIdentity string, response interface{}) { @@ -44,7 +46,7 @@ func (h APIHandler) respond(w http.ResponseWriter, status int, requestIdentity s encoder.SetEscapeHTML(false) err := encoder.Encode(response) if err != nil { - h.logger.Error("encoding response", slog.Any("error", err), slog.Int("status", status), slog.Any("response", response)) + h.logger.Error("encoding response", err, slog.Int("status", status), slog.Any("response", response)) } } diff --git a/handlers/bind.go b/handlers/bind.go index 6d0a5162..b8a900bf 100644 --- a/handlers/bind.go +++ b/handlers/bind.go @@ -22,7 +22,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := blog.New(req.Context(), h.logger, bindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) + logger := h.logger.Session(req.Context(), bindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) version := getAPIVersion(req) asyncAllowed := false diff --git a/handlers/catalog.go b/handlers/catalog.go index 8788d0a0..fc0917d7 100644 --- a/handlers/catalog.go +++ b/handlers/catalog.go @@ -4,8 +4,6 @@ import ( "fmt" "net/http" - "github.com/pivotal-cf/brokerapi/v10/internal/blog" - "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" "github.com/pivotal-cf/brokerapi/v10/middlewares" ) @@ -13,7 +11,7 @@ import ( const getCatalogLogKey = "getCatalog" func (h *APIHandler) Catalog(w http.ResponseWriter, req *http.Request) { - logger := blog.New(req.Context(), h.logger, getCatalogLogKey) + logger := h.logger.Session(req.Context(), getCatalogLogKey) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) services, err := h.serviceBroker.Services(req.Context()) diff --git a/handlers/deprovision.go b/handlers/deprovision.go index dabfbfbe..a56c505d 100644 --- a/handlers/deprovision.go +++ b/handlers/deprovision.go @@ -17,7 +17,7 @@ const deprovisionLogKey = "deprovision" func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := blog.New(req.Context(), h.logger, deprovisionLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), deprovisionLogKey, blog.InstanceID(instanceID)) details := domain.DeprovisionDetails{ PlanID: req.FormValue("plan_id"), diff --git a/handlers/get_binding.go b/handlers/get_binding.go index 88a76a5e..77342f01 100644 --- a/handlers/get_binding.go +++ b/handlers/get_binding.go @@ -19,7 +19,7 @@ func (h APIHandler) GetBinding(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := blog.New(req.Context(), h.logger, getBindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) + logger := h.logger.Session(req.Context(), getBindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/get_instance.go b/handlers/get_instance.go index 2ad1bf69..64b608a9 100644 --- a/handlers/get_instance.go +++ b/handlers/get_instance.go @@ -18,7 +18,7 @@ const getInstanceLogKey = "getInstance" func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := blog.New(req.Context(), h.logger, getInstanceLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), getInstanceLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/last_binding_operation.go b/handlers/last_binding_operation.go index 8c863472..38fcc25a 100644 --- a/handlers/last_binding_operation.go +++ b/handlers/last_binding_operation.go @@ -24,7 +24,7 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques OperationData: req.FormValue("operation"), } - logger := blog.New(req.Context(), h.logger, lastBindingOperationLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), lastBindingOperationLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/last_operation.go b/handlers/last_operation.go index 17de300b..7abc4e64 100644 --- a/handlers/last_operation.go +++ b/handlers/last_operation.go @@ -22,7 +22,7 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { OperationData: req.FormValue("operation"), } - logger := blog.New(req.Context(), h.logger, lastOperationLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), lastOperationLogKey, blog.InstanceID(instanceID)) logger.Info("starting-check-for-operation") diff --git a/handlers/provision.go b/handlers/provision.go index 6552a146..d610cb01 100644 --- a/handlers/provision.go +++ b/handlers/provision.go @@ -15,18 +15,16 @@ import ( ) const ( - provisionLogKey = "provision" - + provisionLogKey = "provision" instanceDetailsLogKey = "instance-details" - - invalidServiceID = "invalid-service-id" - invalidPlanID = "invalid-plan-id" + invalidServiceID = "invalid-service-id" + invalidPlanID = "invalid-plan-id" ) func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := blog.New(req.Context(), h.logger, provisionLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), provisionLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/unbind.go b/handlers/unbind.go index 0ae0bdc2..0a2b3022 100644 --- a/handlers/unbind.go +++ b/handlers/unbind.go @@ -17,7 +17,7 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := blog.New(req.Context(), h.logger, unbindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) + logger := h.logger.Session(req.Context(), unbindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/update.go b/handlers/update.go index 3cb5ede1..b1ccbf6f 100644 --- a/handlers/update.go +++ b/handlers/update.go @@ -18,7 +18,7 @@ const updateLogKey = "update" func (h APIHandler) Update(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := blog.New(req.Context(), h.logger, updateLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), updateLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/internal/blog/blog.go b/internal/blog/blog.go index 24c8ee07..758a4064 100644 --- a/internal/blog/blog.go +++ b/internal/blog/blog.go @@ -1,8 +1,8 @@ // Package blog is the brokerapi logger -// BrokerAPI was originally written to use the CloudFoundry Lager logger, and it relied on some idiosyncrasies -// of that logger that are not supported by the (subsequently written) standard library log/slog logger. -// This package is a wrapper around log/slog that adds back the idiosyncrasies of lager, so that the behavior -// is exactly the same. +// BrokerAPI was originally written to use the CloudFoundry Lager logger (https://github.com/cloudfoundry/lager), +// 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. package blog import ( @@ -24,12 +24,11 @@ type Blog struct { prefix string } -func New(ctx context.Context, logger *slog.Logger, prefix string, supplementary ...slog.Attr) Blog { - var attr []any - for _, s := range supplementary { - attr = append(attr, s) - } +func New(logger *slog.Logger) Blog { + return Blog{logger: logger} +} +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 { attr = append(attr, slog.Any(string(key), value)) @@ -37,13 +36,13 @@ func New(ctx context.Context, logger *slog.Logger, prefix string, supplementary } return Blog{ - logger: logger.With(attr...), - prefix: prefix, + logger: b.logger.With(attr...), + prefix: appendPrefix(b.prefix, prefix), } } -func (b Blog) Error(message string, err error) { - b.logger.Error(join(b.prefix, message), slog.Any(errorKey, err)) +func (b Blog) Error(message string, err error, attr ...any) { + b.logger.Error(join(b.prefix, message), append([]any{slog.Any(errorKey, err)}, attr...)...) } func (b Blog) Info(message string, attr ...any) { @@ -66,3 +65,12 @@ func BindingID(bindingID string) slog.Attr { func join(s ...string) string { return strings.Join(s, ".") } + +func appendPrefix(existing, addition string) string { + switch existing { + case "": + return addition + default: + return join(existing, addition) + } +} diff --git a/internal/blog/blog_test.go b/internal/blog/blog_test.go index d80fa263..7c666c72 100644 --- a/internal/blog/blog_test.go +++ b/internal/blog/blog_test.go @@ -8,9 +8,8 @@ import ( . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" "github.com/onsi/gomega/gbytes" - "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/internal/blog" + "github.com/pivotal-cf/brokerapi/v10/middlewares" ) var _ = Describe("Context data", func() { @@ -28,7 +27,7 @@ var _ = Describe("Context data", func() { buffer := gbytes.NewBuffer() logger := slog.New(slog.NewJSONHandler(buffer, nil)) - blog.New(ctx, logger, "prefix").Info("hello") + blog.New(logger).Session(ctx, "prefix").Info("hello") var receiver map[string]any Expect(json.Unmarshal(buffer.Contents(), &receiver)).To(Succeed()) @@ -43,7 +42,7 @@ var _ = Describe("Context data", func() { buffer := gbytes.NewBuffer() logger := slog.New(slog.NewJSONHandler(buffer, nil)) - blog.New(context.TODO(), logger, "prefix").Info("hello") + blog.New(logger).Session(context.TODO(), "prefix").Info("hello") var receiver map[string]any Expect(json.Unmarshal(buffer.Contents(), &receiver)).To(Succeed())