chore: mostly use the blog logger internally

Externally we take a *slog.Logger, but internally we wrap this
almost everywhere

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,

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

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."))

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."))

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))
  }
 }
 

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

handlers/catalog.go

@@ -4,16 +4,14 @@ 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"
 )
 
 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())

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"),

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))
 

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))
 

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))
 

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")
 

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))
 

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))
 

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))
 

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,26 +24,25 @@ 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))
  }
  }
 
  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)
+ }
+}