From 2d4b1ad4fa5651d317e60cc0dc4f1882aacdc4fb Mon Sep 17 00:00:00 2001 From: George Blue Date: Mon, 29 Jan 2024 11:00:31 +0000 Subject: [PATCH] feat!: introduce logger choice via slog Historically brokerapi has required use of the [`lager`](https://github.com/cloudfoundry/lager) logger. In Go 1.21, structured logging was introduced into the Go standard library via the [`log/slog`](https://pkg.go.dev/log/slog) package, and `slog` [compatability was added](https://github.com/cloudfoundry/lager/commit/4bf49559e32f539b8f97772a2206ffeb2babf178) to `lager`. `brokerapi` has been modified to require a `slog` logger to be passed rather than a `lager` logger. This allows users a choice of logger. Users who still want to use lager can easily do that using the lager/slog compatability: ```go logger := lager.NewLogger(name) brokerAPI := brokerapi.New(serviceBroker, slog.New(lager.NewHandler(logger)), credentials) ``` And users who want to use `slog` or an `slog`-compatible logger can do that instead. A key advantage is that `lager` is no longer a dependency of this package, which simplifies package management for apps that use brokerapi and other libraries which use `lager`. --- .github/workflows/run-tests.yml | 2 +- api.go | 10 +- api_options.go | 10 +- api_test.go | 262 +++++++++--------- domain/apiresponses/failure_responses.go | 9 +- domain/apiresponses/failure_responses_test.go | 20 +- failure_response_test.go | 23 +- go.mod | 6 +- go.sum | 15 +- handlers/api_handler.go | 9 +- handlers/bind.go | 27 +- handlers/catalog.go | 8 +- handlers/catalog_test.go | 4 +- handlers/deprovision.go | 20 +- handlers/get_binding.go | 20 +- handlers/get_instance.go | 19 +- handlers/last_binding_operation.go | 23 +- handlers/last_binding_operation_test.go | 4 +- handlers/last_operation.go | 21 +- handlers/provision.go | 31 ++- handlers/unbind.go | 23 +- handlers/update.go | 21 +- internal/logutil/error.go | 7 + internal/logutil/join.go | 7 + middlewares/api_version_header.go | 25 +- utils/context.go | 9 +- utils/context_test.go | 24 +- 27 files changed, 358 insertions(+), 301 deletions(-) create mode 100644 internal/logutil/error.go create mode 100644 internal/logutil/join.go diff --git a/.github/workflows/run-tests.yml b/.github/workflows/run-tests.yml index 8166233b..d1dabc37 100644 --- a/.github/workflows/run-tests.yml +++ b/.github/workflows/run-tests.yml @@ -15,7 +15,7 @@ jobs: runs-on: ubuntu-latest strategy: matrix: - version: [ 'stable', 'oldstable', '1.20' ] + version: [ 'stable', 'oldstable', '1.21' ] name: Go ${{ matrix.version }} outputs: pr_number: ${{ github.event.number }} diff --git a/api.go b/api.go index 0fbb095f..0baa9f9d 100644 --- a/api.go +++ b/api.go @@ -16,9 +16,9 @@ package brokerapi import ( + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/handlers" ) @@ -28,19 +28,19 @@ type BrokerCredentials struct { Password string } -func New(serviceBroker ServiceBroker, logger lager.Logger, brokerCredentials BrokerCredentials) http.Handler { +func New(serviceBroker ServiceBroker, logger *slog.Logger, brokerCredentials BrokerCredentials) http.Handler { return NewWithOptions(serviceBroker, logger, WithBrokerCredentials(brokerCredentials)) } -func NewWithCustomAuth(serviceBroker ServiceBroker, logger lager.Logger, authMiddleware middlewareFunc) http.Handler { +func NewWithCustomAuth(serviceBroker ServiceBroker, logger *slog.Logger, authMiddleware middlewareFunc) http.Handler { return NewWithOptions(serviceBroker, logger, WithCustomAuth(authMiddleware)) } -func AttachRoutes(router chi.Router, serviceBroker ServiceBroker, logger lager.Logger) { +func AttachRoutes(router chi.Router, serviceBroker ServiceBroker, logger *slog.Logger) { attachRoutes(router, serviceBroker, logger) } -func attachRoutes(router chi.Router, serviceBroker ServiceBroker, logger lager.Logger) { +func attachRoutes(router chi.Router, serviceBroker ServiceBroker, logger *slog.Logger) { apiHandler := handlers.NewApiHandler(serviceBroker, logger) router.Get("/v2/catalog", apiHandler.Catalog) diff --git a/api_options.go b/api_options.go index 488b2417..3a6c51dc 100644 --- a/api_options.go +++ b/api_options.go @@ -16,9 +16,9 @@ package brokerapi import ( + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/auth" "github.com/pivotal-cf/brokerapi/v10/domain" @@ -27,7 +27,7 @@ import ( type middlewareFunc func(http.Handler) http.Handler -func NewWithOptions(serviceBroker domain.ServiceBroker, logger lager.Logger, opts ...Option) http.Handler { +func NewWithOptions(serviceBroker domain.ServiceBroker, logger *slog.Logger, opts ...Option) http.Handler { cfg := newDefaultConfig(logger) WithOptions(append(opts, withDefaultMiddleware())...)(cfg) attachRoutes(cfg.router, serviceBroker, logger) @@ -70,7 +70,7 @@ func WithEncodedPath() Option { func withDefaultMiddleware() Option { return func(c *config) { if !c.customRouter { - c.router.Use(middlewares.APIVersionMiddleware{LoggerFactory: c.logger}.ValidateAPIVersionHdr) + c.router.Use(middlewares.APIVersionMiddleware{Logger: c.logger}.ValidateAPIVersionHdr) c.router.Use(middlewares.AddCorrelationIDToContext) c.router.Use(middlewares.AddOriginatingIdentityToContext) c.router.Use(middlewares.AddInfoLocationToContext) @@ -87,7 +87,7 @@ func WithOptions(opts ...Option) Option { } } -func newDefaultConfig(logger lager.Logger) *config { +func newDefaultConfig(logger *slog.Logger) *config { return &config{ router: chi.NewRouter(), customRouter: false, @@ -98,5 +98,5 @@ func newDefaultConfig(logger lager.Logger) *config { type config struct { router chi.Router customRouter bool - logger lager.Logger + logger *slog.Logger } diff --git a/api_test.go b/api_test.go index 6bf33f9d..b4998a57 100644 --- a/api_test.go +++ b/api_test.go @@ -21,31 +21,31 @@ import ( "encoding/json" "errors" "fmt" + "log/slog" "net/http" "net/http/httptest" "net/url" "strings" - "code.cloudfoundry.org/lager/v3" - "code.cloudfoundry.org/lager/v3/lagertest" "github.com/drewolson/testflight" "github.com/go-chi/chi/v5" . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" + "github.com/onsi/gomega/gbytes" "github.com/pivotal-cf/brokerapi/v10" "github.com/pivotal-cf/brokerapi/v10/fakes" "github.com/pivotal-cf/brokerapi/v10/middlewares" ) var _ = Describe("Service Broker API", func() { - var fakeServiceBroker *fakes.FakeServiceBroker - var brokerAPI http.Handler - var brokerLogger *lagertest.TestLogger - var apiVersion string - var credentials = brokerapi.BrokerCredentials{ - Username: "username", - Password: "password", - } + var ( + fakeServiceBroker *fakes.FakeServiceBroker + brokerAPI http.Handler + logBuffer *gbytes.Buffer + brokerLogger *slog.Logger + apiVersion string + credentials brokerapi.BrokerCredentials + ) const requestIdentity = "Request Identity Name" @@ -82,17 +82,25 @@ var _ = Describe("Service Broker API", func() { return makeInstanceProvisioningRequest(instanceID, details, acceptsIncompleteFlag) } - lastLogLine := func() lager.LogFormat { - noOfLogLines := len(brokerLogger.Logs()) + lastLogLine := func() (result map[string]any) { + GinkgoHelper() + + lines := strings.Split(strings.TrimSpace(string(logBuffer.Contents())), "\n") + noOfLogLines := len(lines) if noOfLogLines == 0 { Fail("expected some log lines but there were none") } - return brokerLogger.Logs()[noOfLogLines-1] + Expect(json.Unmarshal([]byte(lines[noOfLogLines-1]), &result)).To(Succeed(), fmt.Sprintf("failed to parse JSON: %q", lines[noOfLogLines-1])) + return } BeforeEach(func() { apiVersion = "2.14" + credentials = brokerapi.BrokerCredentials{ + Username: "username", + Password: "password", + } fakeServiceBroker = &fakes.FakeServiceBroker{ ProvisionedInstances: map[string]brokerapi.ProvisionDetails{}, BoundBindings: map[string]brokerapi.BindDetails{}, @@ -100,7 +108,9 @@ var _ = Describe("Service Broker API", func() { ServiceID: "0A789746-596F-4CEA-BFAC-A0795DA056E3", PlanID: "plan-id", } - brokerLogger = lagertest.NewTestLogger("broker-api") + + logBuffer = gbytes.NewBuffer() + brokerLogger = slog.New(slog.NewJSONHandler(logBuffer, nil)) brokerAPI = brokerapi.NewWithOptions(fakeServiceBroker, brokerLogger, brokerapi.WithBrokerCredentials(credentials)) }) @@ -609,8 +619,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.Code).To(Equal(http.StatusPreconditionFailed)) Expect(response.Header().Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header not set")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header not set")) }) It("has wrong version of API", func() { @@ -618,8 +628,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.Code).To(Equal(http.StatusPreconditionFailed)) Expect(response.Header().Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header must be 2.x")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header must be 2.x")) }) }) }) @@ -834,8 +844,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { makeInstanceProvisioningRequest(instanceID, provisionDetails, "") - Expect(lastLogLine().Message).To(ContainSubstring(".provision.instance-limit-reached")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("instance limit for this service has been reached")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.instance-limit-reached")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "instance limit for this service has been reached")) }) }) @@ -853,8 +863,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { makeInstanceProvisioningRequest(instanceID, provisionDetails, "") - Expect(lastLogLine().Message).To(ContainSubstring(".provision.unknown-error")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("broker failed")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.unknown-error")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "broker failed")) }) }) @@ -876,8 +886,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { makeInstanceProvisioningRequest(instanceID, provisionDetails, "") - Expect(lastLogLine().Message).To(ContainSubstring(".provision.interesting-failure")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("I failed in unique and interesting ways")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.interesting-failure")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "I failed in unique and interesting ways")) }) }) @@ -895,8 +905,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { makeInstanceProvisioningRequest(instanceID, provisionDetails, "") - Expect(lastLogLine().Message).To(ContainSubstring(".provision.invalid-raw-params")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("The format of the parameters is not valid JSON")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.invalid-raw-params")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "The format of the parameters is not valid JSON")) }) }) @@ -930,7 +940,7 @@ var _ = Describe("Service Broker API", func() { It("logs a message", func() { makeBadInstanceProvisioningRequest(instanceID) - Expect(lastLogLine().Message).To(ContainSubstring(".provision.invalid-service-details")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.invalid-service-details")) }) }) }) @@ -985,8 +995,8 @@ var _ = Describe("Service Broker API", func() { provisionDetails["space_guid"] = "space_guid" }() makeInstanceProvisioningRequest(instanceID, provisionDetails, "") - Expect(lastLogLine().Message).To(ContainSubstring(".provision.instance-already-exists")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("instance already exists")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.instance-already-exists")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "instance already exists")) }) }) @@ -1127,8 +1137,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header not set")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header not set")) }) It("has wrong version of API", func() { @@ -1138,8 +1148,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header must be 2.x")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header must be 2.x")) }) It("missing service_id", func() { @@ -1149,8 +1159,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".provision.service-id-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("service_id missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.service-id-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "service_id missing")) }) It("missing plan_id", func() { @@ -1160,8 +1170,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".provision.plan-id-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("plan_id missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.plan-id-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "plan_id missing")) }) It("service_id not in the catalog", func() { @@ -1171,8 +1181,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".provision.invalid-service-id")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("service-id not in the catalog")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.invalid-service-id")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "service-id not in the catalog")) }) It("plan_id not in the catalog", func() { @@ -1182,8 +1192,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".provision.invalid-plan-id")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("plan-id not in the catalog")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "provision.invalid-plan-id")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "plan-id not in the catalog")) }) }) }) @@ -1257,8 +1267,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(updateRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header not set")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header not set")) }) It("has wrong version of API", func() { @@ -1267,8 +1277,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(updateRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header must be 2.x")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header must be 2.x")) }) It("missing service-id", func() { @@ -1278,8 +1288,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(updateRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".update.service-id-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("service_id missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "update.service-id-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "service_id missing")) }) }) @@ -1581,8 +1591,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { instanceID = uniqueInstanceID() makeInstanceDeprovisioningRequest(instanceID, "") - Expect(lastLogLine().Message).To(ContainSubstring(".deprovision.instance-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("instance does not exist")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "deprovision.instance-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "instance does not exist")) }) }) @@ -1615,8 +1625,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { makeInstanceDeprovisioningRequest(instanceID, "") - Expect(lastLogLine().Message).To(ContainSubstring(".deprovision.unknown-error")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("broker failed")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "deprovision.unknown-error")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "broker failed")) }) }) @@ -1639,8 +1649,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { makeInstanceDeprovisioningRequest(instanceID, "") - Expect(lastLogLine().Message).To(ContainSubstring(".deprovision.interesting-failure")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("I failed in unique and interesting ways")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "deprovision.interesting-failure")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "I failed in unique and interesting ways")) }) }) }) @@ -1651,8 +1661,8 @@ var _ = Describe("Service Broker API", func() { response := makeInstanceDeprovisioningRequestFull("instance-id", "service-id", "plan-id", "") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header not set")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header not set")) }) It("has wrong version of API", func() { @@ -1660,24 +1670,24 @@ var _ = Describe("Service Broker API", func() { response := makeInstanceDeprovisioningRequestFull("instance-id", "service-id", "plan-id", "") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header must be 2.x")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header must be 2.x")) }) It("missing service-id", func() { response := makeInstanceDeprovisioningRequestFull("instance-id", "", "plan-id", "") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".deprovision.service-id-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("service_id missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "deprovision.service-id-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "service_id missing")) }) It("missing plan-id", func() { response := makeInstanceDeprovisioningRequestFull("instance-id", "service-id", "", "") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".deprovision.plan-id-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("plan_id missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "deprovision.plan-id-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "plan_id missing")) }) }) }) @@ -1690,8 +1700,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusUnprocessableEntity)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("broker-api.getInstance.fire")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("some error")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "getInstance.fire")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "some error")) }) It("returns 500 when it fails with an unknown error", func() { @@ -1701,8 +1711,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusInternalServerError)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("broker-api.getInstance.unknown-error")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("failed to get instance")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "getInstance.unknown-error")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "failed to get instance")) }) Context("the request is malformed", func() { @@ -1711,8 +1721,8 @@ var _ = Describe("Service Broker API", func() { response := makeGetInstanceRequest("instance-id") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header not set")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header not set")) }) It("has wrong version of API", func() { @@ -1720,8 +1730,8 @@ var _ = Describe("Service Broker API", func() { response := makeGetInstanceRequest("instance-id") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header must be 2.x")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header must be 2.x")) }) It("is using api version < 2.14", func() { @@ -1730,8 +1740,8 @@ var _ = Describe("Service Broker API", func() { Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("broker-api.getInstance.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("get instance endpoint only supported starting with OSB version 2.14")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "getInstance.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "get instance endpoint only supported starting with OSB version 2.14")) }) It("missing instance-id", func() { @@ -2137,8 +2147,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { instanceID = uniqueInstanceID() makeBindingRequest(instanceID, uniqueBindingID(), details) - Expect(lastLogLine().Message).To(ContainSubstring(".bind.instance-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("instance does not exist")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "bind.instance-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "instance does not exist")) }) }) @@ -2193,8 +2203,8 @@ var _ = Describe("Service Broker API", func() { makeBindingRequest(instanceID, uniqueBindingID(), details) makeBindingRequest(instanceID, uniqueBindingID(), details) - Expect(lastLogLine().Message).To(ContainSubstring(".bind.binding-already-exists")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("binding already exists")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "bind.binding-already-exists")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "binding already exists")) }) }) @@ -2213,8 +2223,8 @@ var _ = Describe("Service Broker API", func() { It("logs a detailed error message", func() { makeBindingRequest(uniqueInstanceID(), uniqueBindingID(), details) - Expect(lastLogLine().Message).To(ContainSubstring(".bind.unknown-error")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("unknown error")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "bind.unknown-error")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "unknown error")) }) }) @@ -2236,8 +2246,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { makeBindingRequest(uniqueInstanceID(), uniqueBindingID(), details) - Expect(lastLogLine().Message).To(ContainSubstring(".bind.interesting-failure")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("I failed in unique and interesting ways")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "bind.interesting-failure")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "I failed in unique and interesting ways")) }) }) @@ -2303,35 +2313,34 @@ var _ = Describe("Service Broker API", func() { response := makeBindingRequestWithSpecificAPIVersion(instanceID, bindingID, map[string]interface{}{}, "", false) Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(bindingRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header not set")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header not set")) }) It("has wrong version of API", func() { response := makeBindingRequestWithSpecificAPIVersion(instanceID, bindingID, map[string]interface{}{}, "1.14", false) Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(bindingRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header must be 2.x")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header must be 2.x")) }) It("missing service-id", func() { response := makeBindingRequestWithSpecificAPIVersion(instanceID, bindingID, map[string]interface{}{"plan_id": "123"}, "2.14", false) Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(bindingRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".bind.service-id-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("service_id missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "bind.service-id-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "service_id missing")) }) It("missing plan-id", func() { response := makeBindingRequestWithSpecificAPIVersion(instanceID, bindingID, map[string]interface{}{"service_id": "123"}, "2.14", false) Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(bindingRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".bind.plan-id-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("plan_id missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "bind.plan-id-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "plan_id missing")) }) }) - }) Describe("unbinding", func() { @@ -2384,32 +2393,32 @@ var _ = Describe("Service Broker API", func() { response := makeUnbindingRequestWithServiceIDPlanID(instanceID, bindingID, "service-id", "plan-id", "") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(unbindRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header not set")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header not set")) }) It("has wrong version of API", func() { response := makeUnbindingRequestWithServiceIDPlanID(instanceID, bindingID, "service-id", "plan-id", "1.1") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(unbindRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header must be 2.x")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header must be 2.x")) }) It("missing service-id", func() { response := makeUnbindingRequestWithServiceIDPlanID(instanceID, bindingID, "", "plan-id", "2.13") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(unbindRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".unbind.service-id-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("service_id missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "unbind.service-id-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "service_id missing")) }) It("missing plan-id", func() { response := makeUnbindingRequestWithServiceIDPlanID(instanceID, bindingID, "service-id", "", "2.13") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusBadRequest)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(unbindRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring(".unbind.plan-id-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("plan_id missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "unbind.plan-id-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "plan_id missing")) }) }) @@ -2452,8 +2461,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error message", func() { makeUnbindingRequest(instanceID, "does-not-exist") - Expect(lastLogLine().Message).To(ContainSubstring(".unbind.binding-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("binding does not exist")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "unbind.binding-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "binding does not exist")) }) }) }) @@ -2472,8 +2481,8 @@ var _ = Describe("Service Broker API", func() { instanceID = uniqueInstanceID() makeUnbindingRequest(instanceID, uniqueBindingID()) - Expect(lastLogLine().Message).To(ContainSubstring(".unbind.instance-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("instance does not exist")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "unbind.instance-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "instance does not exist")) }) }) @@ -2492,8 +2501,8 @@ var _ = Describe("Service Broker API", func() { It("logs a detailed error message", func() { makeUnbindingRequest(uniqueInstanceID(), uniqueBindingID()) - Expect(lastLogLine().Message).To(ContainSubstring(".unbind.unknown-error")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("unknown error")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "unbind.unknown-error")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "unknown error")) }) }) @@ -2515,8 +2524,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { makeUnbindingRequest(uniqueInstanceID(), uniqueBindingID()) - Expect(lastLogLine().Message).To(ContainSubstring(".unbind.interesting-failure")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("I failed in unique and interesting ways")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "unbind.interesting-failure")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "I failed in unique and interesting ways")) }) }) }) @@ -2562,14 +2571,19 @@ var _ = Describe("Service Broker API", func() { instanceID := "instanceID" response := makeLastOperationRequest(instanceID, "", "2.14") - logs := brokerLogger.Logs() + var logs []map[string]any + for i, line := range strings.Split(strings.TrimSpace(string(logBuffer.Contents())), "\n") { + var receiver map[string]any + Expect(json.Unmarshal([]byte(line), &receiver)).To(Succeed(), fmt.Sprintf("line %d", i)) + logs = append(logs, receiver) + } - Expect(logs[0].Message).To(ContainSubstring(".lastOperation.starting-check-for-operation")) - Expect(logs[0].Data["instance-id"]).To(ContainSubstring(instanceID)) + Expect(logs[0]).To(HaveKeyWithValue("msg", "lastOperation.starting-check-for-operation")) + Expect(logs[0]).To(HaveKeyWithValue("instance-id", instanceID)) - Expect(logs[1].Message).To(ContainSubstring(".lastOperation.done-check-for-operation")) - Expect(logs[1].Data["instance-id"]).To(ContainSubstring(instanceID)) - Expect(logs[1].Data["state"]).To(ContainSubstring(string(fakeServiceBroker.LastOperationState))) + Expect(logs[1]).To(HaveKeyWithValue("msg", "lastOperation.done-check-for-operation")) + Expect(logs[1]).To(HaveKeyWithValue("instance-id", instanceID)) + Expect(logs[1]).To(HaveKeyWithValue("state", BeEquivalentTo(fakeServiceBroker.LastOperationState))) Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusOK)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) @@ -2581,8 +2595,8 @@ var _ = Describe("Service Broker API", func() { instanceID := "non-existing" response := makeLastOperationRequest(instanceID, "", "2.14") - Expect(lastLogLine().Message).To(ContainSubstring(".lastOperation.instance-missing")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("instance does not exist")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "lastOperation.instance-missing")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "instance does not exist")) Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusGone)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) @@ -2605,8 +2619,8 @@ var _ = Describe("Service Broker API", func() { It("logs a detailed error message", func() { makeLastOperationRequest("instanceID", "", "2.14") - Expect(lastLogLine().Message).To(ContainSubstring(".lastOperation.unknown-error")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("unknown error")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "lastOperation.unknown-error")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "unknown error")) }) }) @@ -2628,8 +2642,8 @@ var _ = Describe("Service Broker API", func() { It("logs an appropriate error", func() { makeLastOperationRequest("instanceID", "", "2.14") - Expect(lastLogLine().Message).To(ContainSubstring(".lastOperation.interesting-failure")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("I failed in unique and interesting ways")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "lastOperation.interesting-failure")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "I failed in unique and interesting ways")) }) }) @@ -2638,16 +2652,16 @@ var _ = Describe("Service Broker API", func() { response := makeLastOperationRequest("instance-id", "", "") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header not set")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header not set")) }) It("has wrong version of API", func() { response := makeLastOperationRequest("instance-id", "", "1.2") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusPreconditionFailed)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(requestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("version-header-check.broker-api-version-invalid")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("X-Broker-API-Version Header must be 2.x")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "version-header-check.broker-api-version-invalid")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "X-Broker-API-Version Header must be 2.x")) }) }) }) @@ -2659,8 +2673,8 @@ var _ = Describe("Service Broker API", func() { response := makeGetBindingRequestWithSpecificAPIVersion("some-instance", "some-binding", "2.14") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusInternalServerError)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(bindingRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("broker-api.getBinding.unknown-error")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("something failed")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "getBinding.unknown-error")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "something failed")) }) It("returns the appropriate status code when it fails with a known error", func() { @@ -2669,8 +2683,8 @@ var _ = Describe("Service Broker API", func() { response := makeGetBindingRequestWithSpecificAPIVersion("some-instance", "some-binding", "2.14") Expect(response.RawResponse).To(HaveHTTPStatus(http.StatusUnprocessableEntity)) Expect(response.Header.Get("X-Broker-API-Request-Identity")).To(Equal(bindingRequestIdentity)) - Expect(lastLogLine().Message).To(ContainSubstring("broker-api.getBinding.fire")) - Expect(lastLogLine().Data["error"]).To(ContainSubstring("some error")) + Expect(lastLogLine()).To(HaveKeyWithValue("msg", "getBinding.fire")) + Expect(lastLogLine()).To(HaveKeyWithValue("error", "some error")) }) }) diff --git a/domain/apiresponses/failure_responses.go b/domain/apiresponses/failure_responses.go index cce32839..8d171225 100644 --- a/domain/apiresponses/failure_responses.go +++ b/domain/apiresponses/failure_responses.go @@ -2,9 +2,10 @@ package apiresponses import ( "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" ) // FailureResponse can be returned from any of the `ServiceBroker` interface methods @@ -43,12 +44,10 @@ func (f *FailureResponse) ErrorResponse() interface{} { } } -// ValidatedStatusCode returns the HTTP response status code. If the code is not 4xx -// or 5xx, an InternalServerError will be returned instead. -func (f *FailureResponse) ValidatedStatusCode(logger lager.Logger) int { +func (f *FailureResponse) ValidatedStatusCode(prefix string, logger *slog.Logger) int { if f.statusCode < 400 || 600 <= f.statusCode { if logger != nil { - logger.Error("validating-status-code", fmt.Errorf("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) + logger.Error(logutil.Join(prefix, "validating-status-code"), slog.String("error", "Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) } return http.StatusInternalServerError } diff --git a/domain/apiresponses/failure_responses_test.go b/domain/apiresponses/failure_responses_test.go index 90b76b8c..738dc314 100644 --- a/domain/apiresponses/failure_responses_test.go +++ b/domain/apiresponses/failure_responses_test.go @@ -2,14 +2,13 @@ package apiresponses_test import ( "errors" + "log/slog" "net/http" . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" - "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" - - "code.cloudfoundry.org/lager/v3" "github.com/onsi/gomega/gbytes" + "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" ) var _ = Describe("FailureResponse", func() { @@ -47,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(nil)).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) @@ -63,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(nil)).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())) }) @@ -72,26 +71,25 @@ 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("", 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(nil)).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(nil)).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 := lager.NewLogger("test") - logger.RegisterSink(lager.NewWriterSink(log, lager.DEBUG)) + logger := slog.New(slog.NewJSONHandler(log, nil)) failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), 600, "log-key")) - failureResponse.ValidatedStatusCode(logger) + 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 65e3a0fa..3a78044b 100644 --- a/failure_response_test.go +++ b/failure_response_test.go @@ -16,17 +16,15 @@ package brokerapi_test import ( - "github.com/pivotal-cf/brokerapi/v10" - "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" - "errors" - + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" "github.com/onsi/gomega/gbytes" + "github.com/pivotal-cf/brokerapi/v10" + "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" ) var _ = Describe("FailureResponse", func() { @@ -64,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(nil)).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) @@ -80,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(nil)).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())) }) @@ -89,26 +87,25 @@ 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("", 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(nil)).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(nil)).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 := lager.NewLogger("test") - logger.RegisterSink(lager.NewWriterSink(log, lager.DEBUG)) + logger := slog.New(slog.NewJSONHandler(log, nil)) failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), 600, "log-key")) - failureResponse.ValidatedStatusCode(logger) + 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/go.mod b/go.mod index 2ee125dd..e659d6f7 100644 --- a/go.mod +++ b/go.mod @@ -1,9 +1,8 @@ module github.com/pivotal-cf/brokerapi/v10 -go 1.20 +go 1.21 require ( - code.cloudfoundry.org/lager/v3 v3.0.3 github.com/drewolson/testflight v1.0.0 github.com/go-chi/chi/v5 v5.0.11 github.com/maxbrunsfeld/counterfeiter/v6 v6.8.1 @@ -21,12 +20,13 @@ require ( github.com/google/go-cmp v0.6.0 // indirect github.com/google/pprof v0.0.0-20210407192527-94a9f03dee38 // indirect github.com/google/uuid v1.0.0 // indirect - github.com/openzipkin/zipkin-go v0.4.2 // indirect + github.com/kr/text v0.2.0 // indirect golang.org/x/exp/typeparams v0.0.0-20221208152030-732eee02a75a // indirect golang.org/x/mod v0.14.0 // indirect golang.org/x/net v0.20.0 // indirect golang.org/x/sys v0.16.0 // indirect golang.org/x/text v0.14.0 // indirect golang.org/x/tools v0.17.0 // indirect + google.golang.org/protobuf v1.31.0 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect ) diff --git a/go.sum b/go.sum index af155361..115ddbb0 100644 --- a/go.sum +++ b/go.sum @@ -1,5 +1,3 @@ -code.cloudfoundry.org/lager/v3 v3.0.3 h1:/UTmadZfIaKuT/whEinSxK1mzRfNu1uPfvjFfGqiwzM= -code.cloudfoundry.org/lager/v3 v3.0.3/go.mod h1:Zn5q1SrIuuHjEUE7xerMKt3ztunrJQCZETAo7rV0CH8= github.com/BurntSushi/toml v1.2.1 h1:9F2/+DoOYIOksmaJFPw1tGFy1eDnIJXg+UHjuD8lTak= github.com/BurntSushi/toml v1.2.1/go.mod h1:CxXYINrC8qIiEnFrOxCa7Jy5BFHlXnUU2pbicEuybxQ= github.com/bmizerany/assert v0.0.0-20160611221934-b7ed37b82869 h1:DDGfHa7BWjL4YnC6+E63dPcxHo2sUxDIu8g3QgEJdRY= @@ -9,6 +7,7 @@ github.com/bmizerany/pat v0.0.0-20170815010413-6226ea591a40/go.mod h1:8rLXio+Wji github.com/chzyer/logex v1.1.10/go.mod h1:+Ywpsq7O8HXn0nuIou7OrIPyXbp3wmkHB+jjWRnGsAI= github.com/chzyer/readline v0.0.0-20180603132655-2972be24d48e/go.mod h1:nSuG5e5PlCu98SY8svDHJxuZscDgtXS6KTTbou5AhLI= github.com/chzyer/test v0.0.0-20180213035817-a1ea475d72b1/go.mod h1:Q3SI9o4m/ZMnBNeIyt5eFwwo7qiLfzFZmjNmxjkiQlU= +github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= @@ -20,7 +19,10 @@ github.com/go-logr/logr v1.3.0 h1:2y3SDp0ZXuc6/cjLSZ+Q3ir+QB9T/iG5yYRXqsagWSY= github.com/go-logr/logr v1.3.0/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= github.com/go-task/slim-sprig v0.0.0-20230315185526-52ccab3ef572 h1:tfuBGBXKqDEevZMzYi5KSi8KkcZtzBcTgAUUtapy0OI= github.com/go-task/slim-sprig v0.0.0-20230315185526-52ccab3ef572/go.mod h1:9Pwr4B2jHnOSGXyyzV8ROjYa2ojvAY6HCGYYfMoC3Ls= +github.com/golang/protobuf v1.5.0/go.mod h1:FsONVRAS9T7sI+LIUmWTfcYkHO4aIWwzhcaSAoJOfIk= github.com/golang/protobuf v1.5.3 h1:KhyjKVUg7Usr/dYsdSqoFveMYd5ko72D+zANwlG1mmg= +github.com/golang/protobuf v1.5.3/go.mod h1:XVQd3VNwM+JqD3oG2Ue2ip4fOMUkwXdXDdiuN0vRsmY= +github.com/google/go-cmp v0.5.5/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI= github.com/google/go-cmp v0.6.0/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY= github.com/google/pprof v0.0.0-20210407192527-94a9f03dee38 h1:yAJXTCF9TqKcTiHJAE8dj7HMvPfh66eeA2JYW7eFpSE= @@ -32,14 +34,13 @@ github.com/kr/pretty v0.0.0-20160823170715-cfb55aafdaf3 h1:dhwb1Ev84SKKVBfLuhR4b github.com/kr/pretty v0.0.0-20160823170715-cfb55aafdaf3/go.mod h1:Bvhd+E3laJ0AVkG0c9rmtZcnhV0HQ3+c3YxxqTvc/gA= github.com/kr/text v0.0.0-20160504234017-7cafcd837844/go.mod h1:sjUstKUATFIcff4qlB53Kml0wQPtJVc/3fWrmuUmcfA= github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= +github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/maxbrunsfeld/counterfeiter/v6 v6.8.1 h1:NicmruxkeqHjDv03SfSxqmaLuisddudfP3h5wdXFbhM= github.com/maxbrunsfeld/counterfeiter/v6 v6.8.1/go.mod h1:eyp4DdUJAKkr9tvxR3jWhw2mDK7CWABMG5r9uyaKC7I= github.com/onsi/ginkgo/v2 v2.15.0 h1:79HwNRBAZHOEwrczrgSOPy+eFTTlIGELKy5as+ClttY= github.com/onsi/ginkgo/v2 v2.15.0/go.mod h1:HlxMHtYF57y6Dpf+mc5529KKmSq9h2FpCF+/ZkwUxKM= github.com/onsi/gomega v1.31.1 h1:KYppCUK+bUgAZwHOu7EXVBKyQA6ILvOESHkn/tgoqvo= github.com/onsi/gomega v1.31.1/go.mod h1:y40C95dwAD1Nz36SsEnxvfFe8FFfNxzI5eJ0EYGyAy0= -github.com/openzipkin/zipkin-go v0.4.2 h1:zjqfqHjUpPmB3c1GlCvvgsM1G4LkvqQbBDueDOCg/jA= -github.com/openzipkin/zipkin-go v0.4.2/go.mod h1:ZeVkFjuuBiSy13y8vpSDCjMi9GoI3hPpCJSBx/EYFhY= github.com/pborman/uuid v1.2.1 h1:+ZZIw58t/ozdjRaXh/3awHfmWRbzYxJoAdNJxe/3pvw= github.com/pborman/uuid v1.2.1/go.mod h1:X/NO0urCmaxf9VXbdlT7C2Yzkj2IKimNn4k+gtPdI/k= github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= @@ -47,6 +48,7 @@ github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINE github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/sclevine/spec v1.4.0 h1:z/Q9idDcay5m5irkZ28M7PtQM4aOISzOpj4bUPkDee8= +github.com/sclevine/spec v1.4.0/go.mod h1:LvpgJaFyvQzRvc1kaDs0bulYwzC70PbiYjC4QnFHkOM= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/testify v1.6.1 h1:hDPOHmpOpP40lSULcqw7IrRb/u7w6RpDC9399XyoNd0= github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= @@ -58,6 +60,7 @@ golang.org/x/net v0.0.0-20180218175443-cbe0f9307d01/go.mod h1:mL1N/T3taQHkDXs73r golang.org/x/net v0.20.0 h1:aCL9BSgETF1k+blQaYUBx9hJ9LOGP3gAVemcZlf1Kpo= golang.org/x/net v0.20.0/go.mod h1:z8BVo6PvndSri0LbOE3hAn0apkU+1YvI6E70E9jsnvY= golang.org/x/sync v0.6.0 h1:5BMeUDZ7vkXGfEr1x9B4bRcTH4lpkTkpdh0T/J+qjbQ= +golang.org/x/sync v0.6.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk= golang.org/x/sys v0.0.0-20191204072324-ce4227a45e2e/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.16.0 h1:xWw16ngr6ZMtmxDyKyIgsE93KNKz5HKmMa3b8ALHidU= golang.org/x/sys v0.16.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= @@ -65,9 +68,13 @@ golang.org/x/text v0.14.0 h1:ScX5w1eTa3QqT8oi6+ziP7dTV1S2+ALU0bI+0zXKWiQ= golang.org/x/text v0.14.0/go.mod h1:18ZOQIKpY8NJVqYksKHtTdi31H5itFRjB5/qKTNYzSU= golang.org/x/tools v0.17.0 h1:FvmRgNOcs3kOa+T20R1uhfP9F6HgG2mfxDv1vrx1Htc= golang.org/x/tools v0.17.0/go.mod h1:xsh6VxdV005rRVaS6SSAf9oiAqljS7UZUacMZ8Bnsps= +golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +google.golang.org/protobuf v1.26.0-rc.1/go.mod h1:jlhhOSvTdKEhbULTjvd4ARK9grFBp09yW+WbY/TyQbw= google.golang.org/protobuf v1.31.0 h1:g0LDEJHgrBl9N9r17Ru3sqWhkIx2NB67okBHPwC7hs8= +google.golang.org/protobuf v1.31.0/go.mod h1:HV8QOd/L58Z+nl8r43ehVNZIU/HEI6OcFqwMG9pJV4I= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/handlers/api_handler.go b/handlers/api_handler.go index aed79480..192eaa4e 100644 --- a/handlers/api_handler.go +++ b/handlers/api_handler.go @@ -4,10 +4,11 @@ import ( "encoding/json" "errors" "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" "github.com/pivotal-cf/brokerapi/v10/domain" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" ) const ( @@ -29,10 +30,10 @@ var ( type APIHandler struct { serviceBroker domain.ServiceBroker - logger lager.Logger + logger *slog.Logger } -func NewApiHandler(broker domain.ServiceBroker, logger lager.Logger) APIHandler { +func NewApiHandler(broker domain.ServiceBroker, logger *slog.Logger) APIHandler { return APIHandler{broker, logger} } @@ -47,7 +48,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", err, lager.Data{"status": status, "response": response}) + h.logger.Error("encoding response", logutil.Error(err), slog.Int("status", status), slog.Any("response", response)) } } diff --git a/handlers/bind.go b/handlers/bind.go index 4507b2f1..9d83c290 100644 --- a/handlers/bind.go +++ b/handlers/bind.go @@ -3,29 +3,30 @@ package handlers import ( "encoding/json" "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" "github.com/pivotal-cf/brokerapi/v10/middlewares" "github.com/pivotal-cf/brokerapi/v10/utils" ) const ( - invalidBindDetailsErrorKey = "invalid-bind-details" bindLogKey = "bind" + invalidBindDetailsErrorKey = "bind.invalid-bind-details" ) func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := h.logger.Session(bindLogKey, lager.Data{ - instanceIDLogKey: instanceID, - bindingIDLogKey: bindingID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(append( + []any{slog.String(instanceIDLogKey, instanceID), slog.String(bindingIDLogKey, bindingID)}, + utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., + )...) version := getAPIVersion(req) asyncAllowed := false @@ -37,7 +38,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { var details domain.BindDetails if err := json.NewDecoder(req.Body).Decode(&details); err != nil { - logger.Error(invalidBindDetailsErrorKey, err) + logger.Error(invalidBindDetailsErrorKey, logutil.Error(err)) h.respond(w, http.StatusUnprocessableEntity, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -45,7 +46,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { } if details.ServiceID == "" { - logger.Error(serviceIdMissingKey, serviceIdError) + logger.Error(logutil.Join(bindLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) @@ -53,7 +54,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { } if details.PlanID == "" { - logger.Error(planIdMissingKey, planIdError) + logger.Error(logutil.Join(bindLogKey, planIdMissingKey), logutil.Error(planIdError)) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: planIdError.Error(), }) @@ -64,7 +65,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(bindLogKey, logger) errorResponse := err.ErrorResponse() if err == apiresponses.ErrInstanceDoesNotExist { // work around ErrInstanceDoesNotExist having different pre-refactor behaviour to other actions @@ -73,10 +74,10 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { } statusCode = http.StatusNotFound } - logger.Error(err.LoggerAction(), err) + logger.Error(logutil.Join(bindLogKey, err.LoggerAction()), logutil.Error(err)) h.respond(w, statusCode, requestId, errorResponse) default: - logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(bindLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -108,7 +109,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { for _, vol := range binding.VolumeMounts { experimentalConfig, err := json.Marshal(vol.Device.MountConfig) if err != nil { - logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(bindLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{Description: err.Error()}) return } diff --git a/handlers/catalog.go b/handlers/catalog.go index 9bb78a3c..bfe6d5aa 100644 --- a/handlers/catalog.go +++ b/handlers/catalog.go @@ -5,6 +5,7 @@ import ( "net/http" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" "github.com/pivotal-cf/brokerapi/v10/middlewares" "github.com/pivotal-cf/brokerapi/v10/utils" ) @@ -12,16 +13,15 @@ import ( const getCatalogLogKey = "getCatalog" func (h *APIHandler) Catalog(w http.ResponseWriter, req *http.Request) { - logger := h.logger.Session(getCatalogLogKey, nil, - utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)...) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) services, err := h.serviceBroker.Services(req.Context()) if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + logger.Error(logutil.Join(getCatalogLogKey, err.LoggerAction()), logutil.Error(err)) + h.respond(w, err.ValidatedStatusCode(getCatalogLogKey, logger), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/catalog_test.go b/handlers/catalog_test.go index 69057a57..ecce6c3f 100644 --- a/handlers/catalog_test.go +++ b/handlers/catalog_test.go @@ -2,9 +2,9 @@ package handlers_test import ( "context" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" "github.com/pkg/errors" @@ -31,7 +31,7 @@ var _ = Describe("Services", func() { fakeServiceBroker = new(brokerFakes.AutoFakeServiceBroker) - apiHandler = handlers.NewApiHandler(fakeServiceBroker, lager.NewLogger("test")) + apiHandler = handlers.NewApiHandler(fakeServiceBroker, slog.New(slog.NewJSONHandler(GinkgoWriter, nil))) fakeResponseWriter = new(fakes.FakeResponseWriter) fakeResponseWriter.HeaderReturns(http.Header{}) diff --git a/handlers/deprovision.go b/handlers/deprovision.go index 5d9793e0..318bfc44 100644 --- a/handlers/deprovision.go +++ b/handlers/deprovision.go @@ -2,12 +2,13 @@ package handlers import ( "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" "github.com/pivotal-cf/brokerapi/v10/middlewares" "github.com/pivotal-cf/brokerapi/v10/utils" ) @@ -17,9 +18,10 @@ const deprovisionLogKey = "deprovision" func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := h.logger.Session(deprovisionLogKey, lager.Data{ - instanceIDLogKey: instanceID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(append( + []any{slog.String(instanceIDLogKey, instanceID)}, + utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., + )...) details := domain.DeprovisionDetails{ PlanID: req.FormValue("plan_id"), @@ -33,7 +35,7 @@ func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) - logger.Error(serviceIdMissingKey, serviceIdError) + logger.Error(logutil.Join(deprovisionLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) return } @@ -41,7 +43,7 @@ func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: planIdError.Error(), }) - logger.Error(planIdMissingKey, planIdError) + logger.Error(logutil.Join(deprovisionLogKey, planIdMissingKey), logutil.Error(planIdError)) return } @@ -51,10 +53,10 @@ func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + logger.Error(logutil.Join(deprovisionLogKey, err.LoggerAction()), logutil.Error(err)) + h.respond(w, err.ValidatedStatusCode(deprovisionLogKey, logger), requestId, err.ErrorResponse()) default: - logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(deprovisionLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) diff --git a/handlers/get_binding.go b/handlers/get_binding.go index 72d4dd30..8bf61ee6 100644 --- a/handlers/get_binding.go +++ b/handlers/get_binding.go @@ -3,9 +3,11 @@ package handlers import ( "errors" "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" + "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" @@ -19,10 +21,10 @@ func (h APIHandler) GetBinding(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := h.logger.Session(getBindLogKey, lager.Data{ - instanceIDLogKey: instanceID, - bindingIDLogKey: bindingID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(append( + []any{slog.String(instanceIDLogKey, instanceID), slog.String(bindingIDLogKey, bindingID)}, + utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., + )...) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -32,7 +34,7 @@ func (h APIHandler) GetBinding(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusPreconditionFailed, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) - logger.Error(middlewares.ApiVersionInvalidKey, err) + logger.Error(logutil.Join(getBindLogKey, middlewares.ApiVersionInvalidKey), logutil.Error(err)) return } @@ -45,10 +47,10 @@ func (h APIHandler) GetBinding(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + logger.Error(logutil.Join(getBindLogKey, err.LoggerAction()), logutil.Error(err)) + h.respond(w, err.ValidatedStatusCode(getBindLogKey, logger), requestId, err.ErrorResponse()) default: - logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(getBindLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) diff --git a/handlers/get_instance.go b/handlers/get_instance.go index 406cd026..052fd1a7 100644 --- a/handlers/get_instance.go +++ b/handlers/get_instance.go @@ -3,9 +3,11 @@ package handlers import ( "errors" "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" + "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" @@ -18,9 +20,10 @@ const getInstanceLogKey = "getInstance" func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := h.logger.Session(getInstanceLogKey, lager.Data{ - instanceIDLogKey: instanceID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(append( + []any{slog.String(instanceIDLogKey, instanceID)}, + utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., + )...) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -30,7 +33,7 @@ func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusPreconditionFailed, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) - logger.Error(middlewares.ApiVersionInvalidKey, err) + logger.Error(logutil.Join(getInstanceLogKey, middlewares.ApiVersionInvalidKey), logutil.Error(err)) return } @@ -43,10 +46,10 @@ func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + logger.Error(logutil.Join(getInstanceLogKey, err.LoggerAction()), logutil.Error(err)) + h.respond(w, err.ValidatedStatusCode(getInstanceLogKey, logger), requestId, err.ErrorResponse()) default: - logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(getInstanceLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) diff --git a/handlers/last_binding_operation.go b/handlers/last_binding_operation.go index 2e112c36..6e298e44 100644 --- a/handlers/last_binding_operation.go +++ b/handlers/last_binding_operation.go @@ -3,9 +3,11 @@ package handlers import ( "errors" "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" + "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" @@ -24,9 +26,10 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques OperationData: req.FormValue("operation"), } - logger := h.logger.Session(lastBindingOperationLogKey, lager.Data{ - instanceIDLogKey: instanceID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(append( + []any{slog.String(instanceIDLogKey, instanceID)}, + utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., + )...) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -36,20 +39,20 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques h.respond(w, http.StatusPreconditionFailed, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) - logger.Error(middlewares.ApiVersionInvalidKey, err) + logger.Error(logutil.Join(lastBindingOperationLogKey, middlewares.ApiVersionInvalidKey), logutil.Error(err)) return } - logger.Info("starting-check-for-binding-operation") + logger.Info(logutil.Join(lastBindingOperationLogKey, "starting-check-for-binding-operation")) lastOperation, err := h.serviceBroker.LastBindingOperation(req.Context(), instanceID, bindingID, pollDetails) if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + logger.Error(logutil.Join(lastBindingOperationLogKey, err.LoggerAction()), logutil.Error(err)) + h.respond(w, err.ValidatedStatusCode(lastBindingOperationLogKey, logger), requestId, err.ErrorResponse()) default: - logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(lastBindingOperationLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -57,7 +60,7 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques return } - logger.WithData(lager.Data{"state": lastOperation.State}).Info("done-check-for-binding-operation") + logger.Info(logutil.Join(lastBindingOperationLogKey, "done-check-for-binding-operation"), slog.Any("state", lastOperation.State)) lastOperationResponse := apiresponses.LastOperationResponse{ State: lastOperation.State, diff --git a/handlers/last_binding_operation_test.go b/handlers/last_binding_operation_test.go index 080eb9dd..b509503c 100644 --- a/handlers/last_binding_operation_test.go +++ b/handlers/last_binding_operation_test.go @@ -4,10 +4,10 @@ import ( "context" "encoding/json" "fmt" + "log/slog" "net/http" "net/url" - "code.cloudfoundry.org/lager/v3" "github.com/go-chi/chi/v5" . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" @@ -39,7 +39,7 @@ var _ = Describe("LastBindingOperation", func() { fakeServiceBroker = new(brokerFakes.AutoFakeServiceBroker) - apiHandler = handlers.NewApiHandler(fakeServiceBroker, lager.NewLogger("test")) + apiHandler = handlers.NewApiHandler(fakeServiceBroker, slog.New(slog.NewJSONHandler(GinkgoWriter, nil))) fakeResponseWriter = new(fakes.FakeResponseWriter) fakeResponseWriter.HeaderReturns(http.Header{}) diff --git a/handlers/last_operation.go b/handlers/last_operation.go index a3e394f2..a0c2f75a 100644 --- a/handlers/last_operation.go +++ b/handlers/last_operation.go @@ -2,9 +2,11 @@ package handlers import ( "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" + "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" @@ -22,11 +24,12 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { OperationData: req.FormValue("operation"), } - logger := h.logger.Session(lastOperationLogKey, lager.Data{ - instanceIDLogKey: instanceID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(append( + []any{slog.String(instanceIDLogKey, instanceID)}, + utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., + )...) - logger.Info("starting-check-for-operation") + logger.Info(logutil.Join(lastOperationLogKey, "starting-check-for-operation")) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -34,10 +37,10 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + logger.Error(logutil.Join(lastOperationLogKey, err.LoggerAction()), logutil.Error(err)) + h.respond(w, err.ValidatedStatusCode(lastOperationLogKey, logger), requestId, err.ErrorResponse()) default: - logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(lastOperationLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -45,7 +48,7 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { return } - logger.WithData(lager.Data{"state": lastOperation.State}).Info("done-check-for-operation") + logger.Info(logutil.Join(lastOperationLogKey, "done-check-for-operation"), slog.Any("state", lastOperation.State)) lastOperationResponse := apiresponses.LastOperationResponse{ State: lastOperation.State, diff --git a/handlers/provision.go b/handlers/provision.go index 17daf336..2d6f31a4 100644 --- a/handlers/provision.go +++ b/handlers/provision.go @@ -3,9 +3,11 @@ package handlers import ( "encoding/json" "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" + "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" @@ -25,15 +27,16 @@ const ( func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := h.logger.Session(provisionLogKey, lager.Data{ - instanceIDLogKey: instanceID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(append( + []any{slog.String(instanceIDLogKey, instanceID)}, + utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., + )...) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) var details domain.ProvisionDetails if err := json.NewDecoder(req.Body).Decode(&details); err != nil { - logger.Error(invalidServiceDetailsErrorKey, err) + logger.Error(logutil.Join(provisionLogKey, invalidServiceDetailsErrorKey), logutil.Error(err)) h.respond(w, http.StatusUnprocessableEntity, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -41,7 +44,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { } if details.ServiceID == "" { - logger.Error(serviceIdMissingKey, serviceIdError) + logger.Error(logutil.Join(provisionLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) @@ -49,7 +52,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { } if details.PlanID == "" { - logger.Error(planIdMissingKey, planIdError) + logger.Error(logutil.Join(provisionLogKey, planIdMissingKey), logutil.Error(planIdError)) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: planIdError.Error(), }) @@ -66,7 +69,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { } } if !valid { - logger.Error(invalidServiceID, invalidServiceIDError) + logger.Error(logutil.Join(provisionLogKey, invalidServiceID), logutil.Error(invalidServiceIDError)) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: invalidServiceIDError.Error(), }) @@ -84,7 +87,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { } } if !valid { - logger.Error(invalidPlanID, invalidPlanIDError) + logger.Error(logutil.Join(provisionLogKey, invalidPlanID), logutil.Error(invalidPlanIDError)) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: invalidPlanIDError.Error(), }) @@ -93,19 +96,17 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { asyncAllowed := req.FormValue("accepts_incomplete") == "true" - logger = logger.WithData(lager.Data{ - instanceDetailsLogKey: details, - }) + logger = logger.With(slog.Any(instanceDetailsLogKey, details)) provisionResponse, err := h.serviceBroker.Provision(req.Context(), instanceID, details, asyncAllowed) if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + logger.Error(logutil.Join(provisionLogKey, err.LoggerAction()), logutil.Error(err)) + h.respond(w, err.ValidatedStatusCode(provisionLogKey, logger), requestId, err.ErrorResponse()) default: - logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(provisionLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) diff --git a/handlers/unbind.go b/handlers/unbind.go index ca0078bb..9944fddc 100644 --- a/handlers/unbind.go +++ b/handlers/unbind.go @@ -2,9 +2,11 @@ package handlers import ( "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" + "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" @@ -18,10 +20,10 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := h.logger.Session(unbindLogKey, lager.Data{ - instanceIDLogKey: instanceID, - bindingIDLogKey: bindingID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(append( + []any{slog.String(instanceIDLogKey, instanceID), slog.String(bindingIDLogKey, bindingID)}, + utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., + )...) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -34,7 +36,7 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) - logger.Error(serviceIdMissingKey, serviceIdError) + logger.Error(logutil.Join(unbindLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) return } @@ -42,7 +44,7 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: planIdError.Error(), }) - logger.Error(planIdMissingKey, planIdError) + logger.Error(logutil.Join(unbindLogKey, planIdMissingKey), logutil.Error(planIdError)) return } @@ -51,10 +53,10 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + logger.Error(logutil.Join(unbindLogKey, err.LoggerAction()), logutil.Error(err)) + h.respond(w, err.ValidatedStatusCode(unbindLogKey, logger), requestId, err.ErrorResponse()) default: - logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(unbindLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -69,5 +71,4 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { } else { h.respond(w, http.StatusOK, requestId, apiresponses.EmptyResponse{}) } - } diff --git a/handlers/update.go b/handlers/update.go index 84c57df4..02c7a96c 100644 --- a/handlers/update.go +++ b/handlers/update.go @@ -3,10 +3,12 @@ package handlers import ( "encoding/json" "fmt" + "log/slog" "net/http" "strconv" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" + "github.com/go-chi/chi/v5" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" @@ -19,15 +21,16 @@ const updateLogKey = "update" func (h APIHandler) Update(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := h.logger.Session(updateLogKey, lager.Data{ - instanceIDLogKey: instanceID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.With(append( + []any{slog.String(instanceIDLogKey, instanceID)}, + utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., + )...) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) var details domain.UpdateDetails if err := json.NewDecoder(req.Body).Decode(&details); err != nil { - h.logger.Error(invalidServiceDetailsErrorKey, err) + logger.Error(logutil.Join(updateLogKey, invalidServiceDetailsErrorKey), logutil.Error(err)) h.respond(w, http.StatusUnprocessableEntity, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -35,7 +38,7 @@ func (h APIHandler) Update(w http.ResponseWriter, req *http.Request) { } if details.ServiceID == "" { - logger.Error(serviceIdMissingKey, serviceIdError) + logger.Error(logutil.Join(updateLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) @@ -48,10 +51,10 @@ func (h APIHandler) Update(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - h.logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(h.logger), requestId, err.ErrorResponse()) + logger.Error(logutil.Join(updateLogKey, err.LoggerAction()), logutil.Error(err)) + h.respond(w, err.ValidatedStatusCode(updateLogKey, logger), requestId, err.ErrorResponse()) default: - h.logger.Error(unknownErrorKey, err) + logger.Error(logutil.Join(updateLogKey, unknownErrorKey), logutil.Error(err)) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) diff --git a/internal/logutil/error.go b/internal/logutil/error.go new file mode 100644 index 00000000..3ef0f962 --- /dev/null +++ b/internal/logutil/error.go @@ -0,0 +1,7 @@ +package logutil + +import "log/slog" + +func Error(err error) slog.Attr { + return slog.Any("error", err.Error()) +} diff --git a/internal/logutil/join.go b/internal/logutil/join.go new file mode 100644 index 00000000..950588ac --- /dev/null +++ b/internal/logutil/join.go @@ -0,0 +1,7 @@ +package logutil + +import "strings" + +func Join(s ...string) string { + return strings.Join(s, ".") +} diff --git a/middlewares/api_version_header.go b/middlewares/api_version_header.go index cd272572..a7960898 100644 --- a/middlewares/api_version_header.go +++ b/middlewares/api_version_header.go @@ -19,15 +19,20 @@ import ( "encoding/json" "errors" "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/logutil" ) -const ApiVersionInvalidKey = "broker-api-version-invalid" +const ( + ApiVersionInvalidKey = "broker-api-version-invalid" + + apiVersionLogKey = "version-header-check" +) type APIVersionMiddleware struct { - LoggerFactory lager.Logger + Logger *slog.Logger } type ErrorResponse struct { @@ -36,11 +41,9 @@ type ErrorResponse struct { func (m APIVersionMiddleware) ValidateAPIVersionHdr(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { - logger := m.LoggerFactory.Session("version-header-check", lager.Data{}) - err := checkBrokerAPIVersionHdr(req) if err != nil { - logger.Error(ApiVersionInvalidKey, err) + m.Logger.Error(logutil.Join(apiVersionLogKey, ApiVersionInvalidKey), logutil.Error(err)) w.Header().Set("Content-type", "application/json") setBrokerRequestIdentityHeader(req, w) @@ -50,9 +53,13 @@ func (m APIVersionMiddleware) ValidateAPIVersionHdr(next http.Handler) http.Hand errorResp := ErrorResponse{ Description: err.Error(), } - err = json.NewEncoder(w).Encode(errorResp) - if err != nil { - logger.Error("encoding response", err, lager.Data{"status": statusResponse, "response": errorResp}) + if err := json.NewEncoder(w).Encode(errorResp); err != nil { + m.Logger.Error( + logutil.Join(apiVersionLogKey, "encoding response"), + logutil.Error(err), + slog.Int("status", statusResponse), + slog.Any("response", errorResp), + ) } return diff --git a/utils/context.go b/utils/context.go index bd4f4567..397a3117 100644 --- a/utils/context.go +++ b/utils/context.go @@ -2,8 +2,8 @@ package utils import ( "context" + "log/slog" - "code.cloudfoundry.org/lager/v3" "github.com/pivotal-cf/brokerapi/v10/domain" "github.com/pivotal-cf/brokerapi/v10/middlewares" ) @@ -43,13 +43,12 @@ func RetrieveServicePlanFromContext(ctx context.Context) *domain.ServicePlan { return nil } -func DataForContext(context context.Context, dataKeys ...middlewares.ContextKey) lager.Data { - data := lager.Data{} +func ContextAttr(context context.Context, dataKeys ...middlewares.ContextKey) (result []any) { for _, key := range dataKeys { if value := context.Value(key); value != nil { - data[string(key)] = value + result = append(result, slog.Any(string(key), value)) } } - return data + return } diff --git a/utils/context_test.go b/utils/context_test.go index 86bb5b26..958540da 100644 --- a/utils/context_test.go +++ b/utils/context_test.go @@ -2,6 +2,7 @@ package utils_test import ( "context" + "log/slog" . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" @@ -83,10 +84,11 @@ var _ = Describe("Context", func() { expectedValue := "123" ctx = context.WithValue(ctx, testKey, expectedValue) - data := utils.DataForContext(ctx, testKey) - value, ok := data[string(testKey)] - Expect(ok).To(BeTrue()) - Expect(value).Should(Equal(expectedValue)) + data := utils.ContextAttr(ctx, testKey) + Expect(data).To(ConsistOf(slog.Attr{ + Key: string(testKey), + Value: slog.StringValue(expectedValue), + })) }) Context("the key value is a struct", func() { @@ -95,19 +97,19 @@ var _ = Describe("Context", func() { expectedValue := testType{} ctx = context.WithValue(ctx, testKey, expectedValue) - data := utils.DataForContext(ctx, testKey) - value, ok := data[string(testKey)] - Expect(ok).To(BeTrue()) - Expect(value).Should(Equal(expectedValue)) + data := utils.ContextAttr(ctx, testKey) + Expect(data).To(ConsistOf(slog.Attr{ + Key: string(testKey), + Value: slog.AnyValue(expectedValue), + })) }) }) }) Context("the provided key is not in the context", func() { It("returns data without the key", func() { - data := utils.DataForContext(ctx, testKey) - _, ok := data[string(testKey)] - Expect(ok).To(BeFalse()) + data := utils.ContextAttr(ctx, testKey) + Expect(data).To(BeEmpty()) }) }) })