From d4d57915abc6bfc24d1dc43da46d017477734fd8 Mon Sep 17 00:00:00 2001 From: George Blue Date: Tue, 2 Apr 2024 15:56:48 +0100 Subject: [PATCH] feat!: introduce logger choice via slog (#292) ## Breaking Changes This package now accepts a `*slog.Logger` from the Go standard library, rather than a [Lager logger](https://github.com/cloudfoundry/lager). This allows the use of alternative loggers. - This package no longer requires you to import `code.cloudfoundry.org/lager/v3`. - The constructors `New()`, `NewWithCustomAuth()`, `NewWithOptions()`, and also `AttachRoutes()` all take a `*slog.Logger` - `apiresponses.FailureResponse` errors with a `ValidatedStatusCode()` method also take a `*slog.Logger` rather than a Lager logger - The middleware `middlewares.APIVersionMiddleware` has had the `LoggerFactory` field removed, and a new field `Logger` added with type `*slog.Logger`. If you want to continue to use Lager, you can just convert it to a `*slog.Logger`, for which you will need Lager [v3.0.3](https://github.com/cloudfoundry/lager/releases/tag/v3.0.3) for example: ```go logger := lager.NewLogger("a-lager-logger") router := brokerapi.New(serviceBroker, slog.New(lager.NewHandler(logger)), credentials) ``` ## Reasons 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. 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`. Resolves #267 --- .github/workflows/run-tests.yml | 2 +- api.go | 10 +- api_options.go | 16 +- api_test.go | 262 +++++++++--------- domain/apiresponses/failure_responses.go | 7 +- domain/apiresponses/failure_responses_test.go | 8 +- failure_response_test.go | 11 +- go.mod | 5 +- go.sum | 10 +- handlers/api_handler.go | 14 +- handlers/bind.go | 13 +- handlers/catalog.go | 7 +- handlers/catalog_test.go | 4 +- handlers/deprovision.go | 10 +- handlers/get_binding.go | 11 +- handlers/get_instance.go | 11 +- handlers/last_binding_operation.go | 12 +- handlers/last_binding_operation_test.go | 4 +- handlers/last_operation.go | 12 +- handlers/provision.go | 21 +- handlers/unbind.go | 12 +- handlers/update.go | 16 +- internal/blog/blog.go | 122 ++++++++ internal/blog/blog_suite_test.go | 13 + internal/blog/blog_test.go | 54 ++++ middlewares/api_version_header.go | 20 +- utils/context.go | 13 - utils/context_test.go | 38 --- 28 files changed, 427 insertions(+), 311 deletions(-) create mode 100644 internal/blog/blog.go create mode 100644 internal/blog/blog_suite_test.go create mode 100644 internal/blog/blog_test.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 69e51c21..362127ef 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" @@ -30,17 +30,13 @@ type middlewareFunc func(http.Handler) http.Handler type config struct { router chi.Router customRouter bool - logger lager.Logger additionalMiddleware []middlewareFunc } -func NewWithOptions(serviceBroker domain.ServiceBroker, logger lager.Logger, opts ...Option) http.Handler { - cfg := config{ - router: chi.NewRouter(), - logger: logger, - } +func NewWithOptions(serviceBroker domain.ServiceBroker, logger *slog.Logger, opts ...Option) http.Handler { + 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{LoggerFactory: c.logger}.ValidateAPIVersionHdr, + middlewares.APIVersionMiddleware{Logger: logger}.ValidateAPIVersionHdr, middlewares.AddCorrelationIDToContext, middlewares.AddOriginatingIdentityToContext, middlewares.AddInfoLocationToContext, diff --git a/api_test.go b/api_test.go index d6bc04ef..4793747f 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)) }) @@ -611,8 +621,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() { @@ -620,8 +630,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")) }) }) }) @@ -836,8 +846,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")) }) }) @@ -855,8 +865,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")) }) }) @@ -878,8 +888,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")) }) }) @@ -897,8 +907,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")) }) }) @@ -932,7 +942,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")) }) }) }) @@ -987,8 +997,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")) }) }) @@ -1129,8 +1139,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() { @@ -1140,8 +1150,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() { @@ -1151,8 +1161,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() { @@ -1162,8 +1172,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() { @@ -1173,8 +1183,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() { @@ -1184,8 +1194,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")) }) }) }) @@ -1259,8 +1269,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() { @@ -1269,8 +1279,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() { @@ -1280,8 +1290,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")) }) }) @@ -1583,8 +1593,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")) }) }) @@ -1617,8 +1627,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")) }) }) @@ -1641,8 +1651,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")) }) }) }) @@ -1653,8 +1663,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() { @@ -1662,24 +1672,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")) }) }) }) @@ -1692,8 +1702,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() { @@ -1703,8 +1713,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() { @@ -1713,8 +1723,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() { @@ -1722,8 +1732,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() { @@ -1732,8 +1742,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() { @@ -2139,8 +2149,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")) }) }) @@ -2195,8 +2205,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")) }) }) @@ -2215,8 +2225,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")) }) }) @@ -2238,8 +2248,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")) }) }) @@ -2305,35 +2315,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() { @@ -2386,32 +2395,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")) }) }) @@ -2454,8 +2463,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")) }) }) }) @@ -2474,8 +2483,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")) }) }) @@ -2494,8 +2503,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")) }) }) @@ -2517,8 +2526,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")) }) }) }) @@ -2564,14 +2573,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)) @@ -2583,8 +2597,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)) @@ -2607,8 +2621,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")) }) }) @@ -2630,8 +2644,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")) }) }) @@ -2640,16 +2654,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")) }) }) }) @@ -2661,8 +2675,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() { @@ -2671,8 +2685,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..0dd48951 100644 --- a/domain/apiresponses/failure_responses.go +++ b/domain/apiresponses/failure_responses.go @@ -2,9 +2,8 @@ package apiresponses import ( "fmt" + "log/slog" "net/http" - - "code.cloudfoundry.org/lager/v3" ) // FailureResponse can be returned from any of the `ServiceBroker` interface methods @@ -45,10 +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(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("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..ff89664f 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() { @@ -88,8 +87,7 @@ var _ = Describe("FailureResponse", func() { 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) 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..5ec9cd28 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() { @@ -105,8 +103,7 @@ var _ = Describe("FailureResponse", func() { 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) 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 42253a5e..1d8f9926 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.12 github.com/maxbrunsfeld/counterfeiter/v6 v6.8.1 @@ -21,7 +20,7 @@ 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 diff --git a/go.sum b/go.sum index cffb4c61..26f4e987 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= @@ -31,14 +30,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.17.1 h1:V++EzdbhI4ZV4ev0UTIj0PzhzOcReJFyJaLjtSF55M8= github.com/onsi/ginkgo/v2 v2.17.1/go.mod h1:llBI3WDLL9Z6taip6f33H76YcWtJv+7R3HigUjbIBOs= github.com/onsi/gomega v1.32.0 h1:JRYU78fJ1LPxlckP6Txi/EYqJvjtMrDC04/MM5XRHPk= github.com/onsi/gomega v1.32.0/go.mod h1:a4x4gW6Pz2yK1MAmvluYme5lvYTn61afQ2ETw/8n4Lg= -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= @@ -46,6 +44,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= @@ -57,6 +56,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,8 +65,10 @@ 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= google.golang.org/protobuf v1.33.0 h1:uNO2rsAINq/JlFpSdYEKIZ0uKD/R9cpdv0T+yoGwGmI= +google.golang.org/protobuf v1.33.0/go.mod h1:c6P6GXX6sHbq/GpV6MGZEdwhWPcYBgnhAHhKbcUYpos= 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..ddf94246 100644 --- a/handlers/api_handler.go +++ b/handlers/api_handler.go @@ -4,20 +4,18 @@ 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/blog" ) const ( invalidServiceDetailsErrorKey = "invalid-service-details" - instanceIDLogKey = "instance-id" serviceIdMissingKey = "service-id-missing" planIdMissingKey = "plan-id-missing" unknownErrorKey = "unknown-error" - - bindingIDLogKey = "binding-id" ) var ( @@ -29,11 +27,11 @@ var ( type APIHandler struct { serviceBroker domain.ServiceBroker - logger lager.Logger + logger blog.Blog } -func NewApiHandler(broker domain.ServiceBroker, logger lager.Logger) APIHandler { - return APIHandler{broker, logger} +func NewApiHandler(broker domain.ServiceBroker, logger *slog.Logger) APIHandler { + return APIHandler{serviceBroker: broker, logger: blog.New(logger)} } func (h APIHandler) respond(w http.ResponseWriter, status int, requestIdentity string, response interface{}) { @@ -47,7 +45,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", err, slog.Int("status", status), slog.Any("response", response)) } } diff --git a/handlers/bind.go b/handlers/bind.go index 4507b2f1..00f1b52e 100644 --- a/handlers/bind.go +++ b/handlers/bind.go @@ -3,29 +3,26 @@ 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/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const ( - invalidBindDetailsErrorKey = "invalid-bind-details" bindLogKey = "bind" + invalidBindDetailsErrorKey = "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.Session(req.Context(), bindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) version := getAPIVersion(req) asyncAllowed := false @@ -64,7 +61,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - statusCode := err.ValidatedStatusCode(logger) + statusCode := err.ValidatedStatusCode(slog.New(logger)) errorResponse := err.ErrorResponse() if err == apiresponses.ErrInstanceDoesNotExist { // work around ErrInstanceDoesNotExist having different pre-refactor behaviour to other actions diff --git a/handlers/catalog.go b/handlers/catalog.go index 9bb78a3c..c3ea93aa 100644 --- a/handlers/catalog.go +++ b/handlers/catalog.go @@ -2,18 +2,17 @@ package handlers import ( "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) 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.Session(req.Context(), getCatalogLogKey) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) services, err := h.serviceBroker.Services(req.Context()) @@ -21,7 +20,7 @@ func (h *APIHandler) Catalog(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/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..ed45995f 100644 --- a/handlers/deprovision.go +++ b/handlers/deprovision.go @@ -2,14 +2,14 @@ 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/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const deprovisionLogKey = "deprovision" @@ -17,9 +17,7 @@ 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.Session(req.Context(), deprovisionLogKey, blog.InstanceID(instanceID)) details := domain.DeprovisionDetails{ PlanID: req.FormValue("plan_id"), @@ -52,7 +50,7 @@ func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/get_binding.go b/handlers/get_binding.go index 72d4dd30..e3f986e0 100644 --- a/handlers/get_binding.go +++ b/handlers/get_binding.go @@ -3,14 +3,14 @@ package handlers import ( "errors" "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/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const getBindLogKey = "getBinding" @@ -19,10 +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 := h.logger.Session(getBindLogKey, lager.Data{ - instanceIDLogKey: instanceID, - bindingIDLogKey: bindingID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.Session(req.Context(), getBindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -46,7 +43,7 @@ func (h APIHandler) GetBinding(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/get_instance.go b/handlers/get_instance.go index 406cd026..d389a8c3 100644 --- a/handlers/get_instance.go +++ b/handlers/get_instance.go @@ -3,14 +3,15 @@ package handlers import ( "errors" "fmt" + "log/slog" "net/http" - "code.cloudfoundry.org/lager/v3" + "github.com/pivotal-cf/brokerapi/v10/internal/blog" + "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/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const getInstanceLogKey = "getInstance" @@ -18,9 +19,7 @@ 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.Session(req.Context(), getInstanceLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -44,7 +43,7 @@ func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/last_binding_operation.go b/handlers/last_binding_operation.go index 2e112c36..9898437e 100644 --- a/handlers/last_binding_operation.go +++ b/handlers/last_binding_operation.go @@ -3,14 +3,14 @@ package handlers import ( "errors" "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/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const lastBindingOperationLogKey = "lastBindingOperation" @@ -24,9 +24,7 @@ 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.Session(req.Context(), lastBindingOperationLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -47,7 +45,7 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ @@ -57,7 +55,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("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..2cfe759e 100644 --- a/handlers/last_operation.go +++ b/handlers/last_operation.go @@ -2,14 +2,14 @@ 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/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const lastOperationLogKey = "lastOperation" @@ -22,9 +22,7 @@ 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.Session(req.Context(), lastOperationLogKey, blog.InstanceID(instanceID)) logger.Info("starting-check-for-operation") @@ -35,7 +33,7 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ @@ -45,7 +43,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("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..f33afa7f 100644 --- a/handlers/provision.go +++ b/handlers/provision.go @@ -3,31 +3,28 @@ 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/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" "github.com/pivotal-cf/brokerapi/v10/utils" ) 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 := h.logger.Session(provisionLogKey, lager.Data{ - instanceIDLogKey: instanceID, - }, utils.DataForContext(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)) + logger := h.logger.Session(req.Context(), provisionLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -93,9 +90,7 @@ 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) @@ -103,7 +98,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/unbind.go b/handlers/unbind.go index ca0078bb..40fc7a03 100644 --- a/handlers/unbind.go +++ b/handlers/unbind.go @@ -2,14 +2,14 @@ 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/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const unbindLogKey = "unbind" @@ -18,10 +18,7 @@ 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.Session(req.Context(), unbindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -52,7 +49,7 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { switch err := err.(type) { case *apiresponses.FailureResponse: logger.Error(err.LoggerAction(), err) - h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ @@ -69,5 +66,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..cb7548fa 100644 --- a/handlers/update.go +++ b/handlers/update.go @@ -3,15 +3,15 @@ package handlers import ( "encoding/json" "fmt" + "log/slog" "net/http" "strconv" - "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/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const updateLogKey = "update" @@ -19,15 +19,13 @@ 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.Session(req.Context(), updateLogKey, blog.InstanceID(instanceID)) 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(invalidServiceDetailsErrorKey, err) h.respond(w, http.StatusUnprocessableEntity, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -48,10 +46,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(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(slog.New(logger)), requestId, err.ErrorResponse()) default: - h.logger.Error(unknownErrorKey, err) + logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) diff --git a/internal/blog/blog.go b/internal/blog/blog.go new file mode 100644 index 00000000..714e843f --- /dev/null +++ b/internal/blog/blog.go @@ -0,0 +1,122 @@ +// Package blog is the brokerapi logger +// 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. +// It also implements the slog.Handler interface so that it can easily be converted into a slog.Logger. +// This is useful when calling public APIs (such as FailureResponse.ValidatedStatusCode) which take a +// slog.Logger as an input, and because they are public cannot take a Blog as an input. +package blog + +import ( + "context" + "log/slog" + "strings" + + "github.com/pivotal-cf/brokerapi/v10/middlewares" +) + +const ( + instanceIDLogKey = "instance-id" + bindingIDLogKey = "binding-id" + errorKey = "error" +) + +type Blog struct { + logger *slog.Logger + prefix string +} + +func New(logger *slog.Logger) Blog { + return Blog{logger: logger} +} + +// Session emulates a Lager logger session. It returns a new logger that will always log the +// attributes, prefix, and data from the context. +func (b Blog) Session(ctx context.Context, prefix string, attr ...any) Blog { + for _, key := range []middlewares.ContextKey{middlewares.CorrelationIDKey, middlewares.RequestIdentityKey} { + if value := ctx.Value(key); value != nil { + attr = append(attr, slog.Any(string(key), value)) + } + } + + return Blog{ + logger: b.logger.With(attr...), + prefix: appendPrefix(b.prefix, prefix), + } +} + +// Error logs an error. It takes an error type as a convenience, which is different to slog.Logger.Error() +func (b Blog) Error(message string, err error, attr ...any) { + b.logger.Error(join(b.prefix, message), append([]any{slog.Any(errorKey, err)}, attr...)...) +} + +// Info logs information. It behaves a lot file slog.Logger.Info() +func (b Blog) Info(message string, attr ...any) { + b.logger.Info(join(b.prefix, message), attr...) +} + +// With returns a logger that always logs the specified attributes +func (b Blog) With(attr ...any) Blog { + b.logger = b.logger.With(attr...) + return b +} + +// Enabled is required implement the slog.Handler interface +func (b Blog) Enabled(context.Context, slog.Level) bool { + return true +} + +// WithAttrs is required implement the slog.Handler interface +func (b Blog) WithAttrs(attrs []slog.Attr) slog.Handler { + var attributes []any + for _, a := range attrs { + attributes = append(attributes, a) + } + return b.With(attributes...) +} + +// WithGroup is required implement the slog.Handler interface +func (b Blog) WithGroup(string) slog.Handler { + return b +} + +// Handle is required implement the slog.Handler interface +func (b Blog) Handle(_ context.Context, record slog.Record) error { + msg := join(b.prefix, record.Message) + switch record.Level { + case slog.LevelDebug: + b.logger.Debug(msg) + case slog.LevelInfo: + b.logger.Info(msg) + case slog.LevelWarn: + b.logger.Warn(msg) + default: + b.logger.Error(msg) + } + + return nil +} + +// InstanceID creates an attribute from an instance ID +func InstanceID(instanceID string) slog.Attr { + return slog.String(instanceIDLogKey, instanceID) +} + +// BindingID creates an attribute from an binding ID +func BindingID(bindingID string) slog.Attr { + return slog.String(bindingIDLogKey, bindingID) +} + +func join(s ...string) string { + return strings.Join(s, ".") +} + +func appendPrefix(existing, addition string) string { + switch existing { + case "": + return addition + default: + return join(existing, addition) + } +} diff --git a/internal/blog/blog_suite_test.go b/internal/blog/blog_suite_test.go new file mode 100644 index 00000000..efeab197 --- /dev/null +++ b/internal/blog/blog_suite_test.go @@ -0,0 +1,13 @@ +package blog_test + +import ( + "testing" + + . "github.com/onsi/ginkgo/v2" + . "github.com/onsi/gomega" +) + +func TestBlog(t *testing.T) { + RegisterFailHandler(Fail) + RunSpecs(t, "BrokerAPI logger Suite") +} diff --git a/internal/blog/blog_test.go b/internal/blog/blog_test.go new file mode 100644 index 00000000..7c666c72 --- /dev/null +++ b/internal/blog/blog_test.go @@ -0,0 +1,54 @@ +package blog_test + +import ( + "context" + "encoding/json" + "log/slog" + + . "github.com/onsi/ginkgo/v2" + . "github.com/onsi/gomega" + "github.com/onsi/gomega/gbytes" + "github.com/pivotal-cf/brokerapi/v10/internal/blog" + "github.com/pivotal-cf/brokerapi/v10/middlewares" +) + +var _ = Describe("Context data", func() { + When("the context has the values", func() { + It("logs the values", func() { + const ( + correlationID = "fake-correlation-id" + requestID = "fake-request-id" + ) + + ctx := context.TODO() + ctx = context.WithValue(ctx, middlewares.CorrelationIDKey, correlationID) + ctx = context.WithValue(ctx, middlewares.RequestIdentityKey, requestID) + + buffer := gbytes.NewBuffer() + logger := slog.New(slog.NewJSONHandler(buffer, nil)) + + blog.New(logger).Session(ctx, "prefix").Info("hello") + + var receiver map[string]any + Expect(json.Unmarshal(buffer.Contents(), &receiver)).To(Succeed()) + + Expect(receiver).To(HaveKeyWithValue(string(middlewares.CorrelationIDKey), correlationID)) + Expect(receiver).To(HaveKeyWithValue(string(middlewares.RequestIdentityKey), requestID)) + }) + }) + + When("the context does not have the values", func() { + It("does not log them", func() { + buffer := gbytes.NewBuffer() + logger := slog.New(slog.NewJSONHandler(buffer, nil)) + + blog.New(logger).Session(context.TODO(), "prefix").Info("hello") + + var receiver map[string]any + Expect(json.Unmarshal(buffer.Contents(), &receiver)).To(Succeed()) + + Expect(receiver).NotTo(HaveKey(string(middlewares.CorrelationIDKey))) + Expect(receiver).NotTo(HaveKey(string(middlewares.RequestIdentityKey))) + }) + }) +}) diff --git a/middlewares/api_version_header.go b/middlewares/api_version_header.go index cd272572..08df623d 100644 --- a/middlewares/api_version_header.go +++ b/middlewares/api_version_header.go @@ -19,15 +19,18 @@ import ( "encoding/json" "errors" "fmt" + "log/slog" "net/http" - - "code.cloudfoundry.org/lager/v3" ) -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 +39,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(fmt.Sprintf("%s.%s", apiVersionLogKey, ApiVersionInvalidKey), slog.Any("error", err)) w.Header().Set("Content-type", "application/json") setBrokerRequestIdentityHeader(req, w) @@ -50,9 +51,8 @@ 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(fmt.Sprintf("%s.%s", apiVersionLogKey, "encoding response"), slog.Any("error", err), slog.Int("status", statusResponse), slog.Any("response", errorResp)) } return diff --git a/utils/context.go b/utils/context.go index bd4f4567..9b76a396 100644 --- a/utils/context.go +++ b/utils/context.go @@ -3,9 +3,7 @@ package utils import ( "context" - "code.cloudfoundry.org/lager/v3" "github.com/pivotal-cf/brokerapi/v10/domain" - "github.com/pivotal-cf/brokerapi/v10/middlewares" ) type contextKey string @@ -42,14 +40,3 @@ func RetrieveServicePlanFromContext(ctx context.Context) *domain.ServicePlan { } return nil } - -func DataForContext(context context.Context, dataKeys ...middlewares.ContextKey) lager.Data { - data := lager.Data{} - for _, key := range dataKeys { - if value := context.Value(key); value != nil { - data[string(key)] = value - } - } - - return data -} diff --git a/utils/context_test.go b/utils/context_test.go index 86bb5b26..3270771a 100644 --- a/utils/context_test.go +++ b/utils/context_test.go @@ -6,7 +6,6 @@ import ( . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" "github.com/pivotal-cf/brokerapi/v10/domain" - "github.com/pivotal-cf/brokerapi/v10/middlewares" "github.com/pivotal-cf/brokerapi/v10/utils" ) @@ -74,41 +73,4 @@ var _ = Describe("Context", func() { }) }) }) - - Describe("Log data for context", func() { - const testKey middlewares.ContextKey = "test-key" - - Context("the provided key is present in the context", func() { - It("returns data containing the key", 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)) - }) - - Context("the key value is a struct", func() { - It("returns data containing the key", func() { - type testType struct{} - 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)) - }) - }) - }) - - 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()) - }) - }) - }) })