From 62d6db834b9f741de3c40904fa1ab86bab1b3e73 Mon Sep 17 00:00:00 2001 From: George Blue Date: Tue, 6 Feb 2024 22:19:18 +0000 Subject: [PATCH] chore: exclusively use the blog logger internally Externally we take a *slog.Logger, but internally we wrap this everywhere --- domain/apiresponses/failure_responses.go | 8 +- domain/apiresponses/failure_responses_test.go | 20 +- failure_response_test.go | 22 +- fakes/fake_handler.go | 342 ++++++++++++++++++ handlers/api_handler.go | 8 +- handlers/bind.go | 2 +- handlers/catalog.go | 4 +- handlers/deprovision.go | 2 +- handlers/get_binding.go | 2 +- handlers/get_instance.go | 2 +- handlers/last_binding_operation.go | 2 +- handlers/last_operation.go | 2 +- handlers/provision.go | 10 +- handlers/unbind.go | 2 +- handlers/update.go | 2 +- internal/blog/blog.go | 34 +- internal/blog/blog_test.go | 7 +- 17 files changed, 416 insertions(+), 55 deletions(-) create mode 100644 fakes/fake_handler.go 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..f16d4577 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" @@ -10,10 +9,17 @@ import ( . "github.com/onsi/gomega" "github.com/onsi/gomega/gbytes" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" + "github.com/pivotal-cf/brokerapi/v10/fakes" "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) var _ = Describe("FailureResponse", func() { + var fakeLogger blog.Blog + + BeforeEach(func() { + fakeLogger = blog.New(slog.New(&fakes.FakeHandler{})) + }) + 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 +54,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 +70,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 +79,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..a3048987 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" @@ -26,10 +25,19 @@ 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/fakes" "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) +//counterfeiter:generate -o ./fakes log/slog.Handler + var _ = Describe("FailureResponse", func() { + var fakeLogger blog.Blog + + BeforeEach(func() { + fakeLogger = blog.New(slog.New(&fakes.FakeHandler{})) + }) + 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 +72,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 +88,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 +97,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/fakes/fake_handler.go b/fakes/fake_handler.go new file mode 100644 index 00000000..630cf2cd --- /dev/null +++ b/fakes/fake_handler.go @@ -0,0 +1,342 @@ +// Code generated by counterfeiter. DO NOT EDIT. +package fakes + +import ( + "context" + "log/slog" + "sync" +) + +type FakeHandler struct { + EnabledStub func(context.Context, slog.Level) bool + enabledMutex sync.RWMutex + enabledArgsForCall []struct { + arg1 context.Context + arg2 slog.Level + } + enabledReturns struct { + result1 bool + } + enabledReturnsOnCall map[int]struct { + result1 bool + } + HandleStub func(context.Context, slog.Record) error + handleMutex sync.RWMutex + handleArgsForCall []struct { + arg1 context.Context + arg2 slog.Record + } + handleReturns struct { + result1 error + } + handleReturnsOnCall map[int]struct { + result1 error + } + WithAttrsStub func([]slog.Attr) slog.Handler + withAttrsMutex sync.RWMutex + withAttrsArgsForCall []struct { + arg1 []slog.Attr + } + withAttrsReturns struct { + result1 slog.Handler + } + withAttrsReturnsOnCall map[int]struct { + result1 slog.Handler + } + WithGroupStub func(string) slog.Handler + withGroupMutex sync.RWMutex + withGroupArgsForCall []struct { + arg1 string + } + withGroupReturns struct { + result1 slog.Handler + } + withGroupReturnsOnCall map[int]struct { + result1 slog.Handler + } + invocations map[string][][]interface{} + invocationsMutex sync.RWMutex +} + +func (fake *FakeHandler) Enabled(arg1 context.Context, arg2 slog.Level) bool { + fake.enabledMutex.Lock() + ret, specificReturn := fake.enabledReturnsOnCall[len(fake.enabledArgsForCall)] + fake.enabledArgsForCall = append(fake.enabledArgsForCall, struct { + arg1 context.Context + arg2 slog.Level + }{arg1, arg2}) + stub := fake.EnabledStub + fakeReturns := fake.enabledReturns + fake.recordInvocation("Enabled", []interface{}{arg1, arg2}) + fake.enabledMutex.Unlock() + if stub != nil { + return stub(arg1, arg2) + } + if specificReturn { + return ret.result1 + } + return fakeReturns.result1 +} + +func (fake *FakeHandler) EnabledCallCount() int { + fake.enabledMutex.RLock() + defer fake.enabledMutex.RUnlock() + return len(fake.enabledArgsForCall) +} + +func (fake *FakeHandler) EnabledCalls(stub func(context.Context, slog.Level) bool) { + fake.enabledMutex.Lock() + defer fake.enabledMutex.Unlock() + fake.EnabledStub = stub +} + +func (fake *FakeHandler) EnabledArgsForCall(i int) (context.Context, slog.Level) { + fake.enabledMutex.RLock() + defer fake.enabledMutex.RUnlock() + argsForCall := fake.enabledArgsForCall[i] + return argsForCall.arg1, argsForCall.arg2 +} + +func (fake *FakeHandler) EnabledReturns(result1 bool) { + fake.enabledMutex.Lock() + defer fake.enabledMutex.Unlock() + fake.EnabledStub = nil + fake.enabledReturns = struct { + result1 bool + }{result1} +} + +func (fake *FakeHandler) EnabledReturnsOnCall(i int, result1 bool) { + fake.enabledMutex.Lock() + defer fake.enabledMutex.Unlock() + fake.EnabledStub = nil + if fake.enabledReturnsOnCall == nil { + fake.enabledReturnsOnCall = make(map[int]struct { + result1 bool + }) + } + fake.enabledReturnsOnCall[i] = struct { + result1 bool + }{result1} +} + +func (fake *FakeHandler) Handle(arg1 context.Context, arg2 slog.Record) error { + fake.handleMutex.Lock() + ret, specificReturn := fake.handleReturnsOnCall[len(fake.handleArgsForCall)] + fake.handleArgsForCall = append(fake.handleArgsForCall, struct { + arg1 context.Context + arg2 slog.Record + }{arg1, arg2}) + stub := fake.HandleStub + fakeReturns := fake.handleReturns + fake.recordInvocation("Handle", []interface{}{arg1, arg2}) + fake.handleMutex.Unlock() + if stub != nil { + return stub(arg1, arg2) + } + if specificReturn { + return ret.result1 + } + return fakeReturns.result1 +} + +func (fake *FakeHandler) HandleCallCount() int { + fake.handleMutex.RLock() + defer fake.handleMutex.RUnlock() + return len(fake.handleArgsForCall) +} + +func (fake *FakeHandler) HandleCalls(stub func(context.Context, slog.Record) error) { + fake.handleMutex.Lock() + defer fake.handleMutex.Unlock() + fake.HandleStub = stub +} + +func (fake *FakeHandler) HandleArgsForCall(i int) (context.Context, slog.Record) { + fake.handleMutex.RLock() + defer fake.handleMutex.RUnlock() + argsForCall := fake.handleArgsForCall[i] + return argsForCall.arg1, argsForCall.arg2 +} + +func (fake *FakeHandler) HandleReturns(result1 error) { + fake.handleMutex.Lock() + defer fake.handleMutex.Unlock() + fake.HandleStub = nil + fake.handleReturns = struct { + result1 error + }{result1} +} + +func (fake *FakeHandler) HandleReturnsOnCall(i int, result1 error) { + fake.handleMutex.Lock() + defer fake.handleMutex.Unlock() + fake.HandleStub = nil + if fake.handleReturnsOnCall == nil { + fake.handleReturnsOnCall = make(map[int]struct { + result1 error + }) + } + fake.handleReturnsOnCall[i] = struct { + result1 error + }{result1} +} + +func (fake *FakeHandler) WithAttrs(arg1 []slog.Attr) slog.Handler { + var arg1Copy []slog.Attr + if arg1 != nil { + arg1Copy = make([]slog.Attr, len(arg1)) + copy(arg1Copy, arg1) + } + fake.withAttrsMutex.Lock() + ret, specificReturn := fake.withAttrsReturnsOnCall[len(fake.withAttrsArgsForCall)] + fake.withAttrsArgsForCall = append(fake.withAttrsArgsForCall, struct { + arg1 []slog.Attr + }{arg1Copy}) + stub := fake.WithAttrsStub + fakeReturns := fake.withAttrsReturns + fake.recordInvocation("WithAttrs", []interface{}{arg1Copy}) + fake.withAttrsMutex.Unlock() + if stub != nil { + return stub(arg1) + } + if specificReturn { + return ret.result1 + } + return fakeReturns.result1 +} + +func (fake *FakeHandler) WithAttrsCallCount() int { + fake.withAttrsMutex.RLock() + defer fake.withAttrsMutex.RUnlock() + return len(fake.withAttrsArgsForCall) +} + +func (fake *FakeHandler) WithAttrsCalls(stub func([]slog.Attr) slog.Handler) { + fake.withAttrsMutex.Lock() + defer fake.withAttrsMutex.Unlock() + fake.WithAttrsStub = stub +} + +func (fake *FakeHandler) WithAttrsArgsForCall(i int) []slog.Attr { + fake.withAttrsMutex.RLock() + defer fake.withAttrsMutex.RUnlock() + argsForCall := fake.withAttrsArgsForCall[i] + return argsForCall.arg1 +} + +func (fake *FakeHandler) WithAttrsReturns(result1 slog.Handler) { + fake.withAttrsMutex.Lock() + defer fake.withAttrsMutex.Unlock() + fake.WithAttrsStub = nil + fake.withAttrsReturns = struct { + result1 slog.Handler + }{result1} +} + +func (fake *FakeHandler) WithAttrsReturnsOnCall(i int, result1 slog.Handler) { + fake.withAttrsMutex.Lock() + defer fake.withAttrsMutex.Unlock() + fake.WithAttrsStub = nil + if fake.withAttrsReturnsOnCall == nil { + fake.withAttrsReturnsOnCall = make(map[int]struct { + result1 slog.Handler + }) + } + fake.withAttrsReturnsOnCall[i] = struct { + result1 slog.Handler + }{result1} +} + +func (fake *FakeHandler) WithGroup(arg1 string) slog.Handler { + fake.withGroupMutex.Lock() + ret, specificReturn := fake.withGroupReturnsOnCall[len(fake.withGroupArgsForCall)] + fake.withGroupArgsForCall = append(fake.withGroupArgsForCall, struct { + arg1 string + }{arg1}) + stub := fake.WithGroupStub + fakeReturns := fake.withGroupReturns + fake.recordInvocation("WithGroup", []interface{}{arg1}) + fake.withGroupMutex.Unlock() + if stub != nil { + return stub(arg1) + } + if specificReturn { + return ret.result1 + } + return fakeReturns.result1 +} + +func (fake *FakeHandler) WithGroupCallCount() int { + fake.withGroupMutex.RLock() + defer fake.withGroupMutex.RUnlock() + return len(fake.withGroupArgsForCall) +} + +func (fake *FakeHandler) WithGroupCalls(stub func(string) slog.Handler) { + fake.withGroupMutex.Lock() + defer fake.withGroupMutex.Unlock() + fake.WithGroupStub = stub +} + +func (fake *FakeHandler) WithGroupArgsForCall(i int) string { + fake.withGroupMutex.RLock() + defer fake.withGroupMutex.RUnlock() + argsForCall := fake.withGroupArgsForCall[i] + return argsForCall.arg1 +} + +func (fake *FakeHandler) WithGroupReturns(result1 slog.Handler) { + fake.withGroupMutex.Lock() + defer fake.withGroupMutex.Unlock() + fake.WithGroupStub = nil + fake.withGroupReturns = struct { + result1 slog.Handler + }{result1} +} + +func (fake *FakeHandler) WithGroupReturnsOnCall(i int, result1 slog.Handler) { + fake.withGroupMutex.Lock() + defer fake.withGroupMutex.Unlock() + fake.WithGroupStub = nil + if fake.withGroupReturnsOnCall == nil { + fake.withGroupReturnsOnCall = make(map[int]struct { + result1 slog.Handler + }) + } + fake.withGroupReturnsOnCall[i] = struct { + result1 slog.Handler + }{result1} +} + +func (fake *FakeHandler) Invocations() map[string][][]interface{} { + fake.invocationsMutex.RLock() + defer fake.invocationsMutex.RUnlock() + fake.enabledMutex.RLock() + defer fake.enabledMutex.RUnlock() + fake.handleMutex.RLock() + defer fake.handleMutex.RUnlock() + fake.withAttrsMutex.RLock() + defer fake.withAttrsMutex.RUnlock() + fake.withGroupMutex.RLock() + defer fake.withGroupMutex.RUnlock() + copiedInvocations := map[string][][]interface{}{} + for key, value := range fake.invocations { + copiedInvocations[key] = value + } + return copiedInvocations +} + +func (fake *FakeHandler) recordInvocation(key string, args []interface{}) { + fake.invocationsMutex.Lock() + defer fake.invocationsMutex.Unlock() + if fake.invocations == nil { + fake.invocations = map[string][][]interface{}{} + } + if fake.invocations[key] == nil { + fake.invocations[key] = [][]interface{}{} + } + fake.invocations[key] = append(fake.invocations[key], args) +} + +var _ slog.Handler = new(FakeHandler) 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())