From 8870aa5d14c40f382f39993945afc4127ef47a84 Mon Sep 17 00:00:00 2001 From: George Blue Date: Mon, 29 Jan 2024 11:00:31 +0000 Subject: [PATCH 1/6] 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 | 8 +- api_test.go | 262 +++++++++--------- domain/apiresponses/failure_responses.go | 9 +- domain/apiresponses/failure_responses_test.go | 20 +- failure_response_test.go | 23 +- go.mod | 5 +- go.sum | 10 +- 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, 351 insertions(+), 300 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 69e51c21..becf23af 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,11 +30,11 @@ type middlewareFunc func(http.Handler) http.Handler type config struct { router chi.Router customRouter bool - logger lager.Logger + logger *slog.Logger additionalMiddleware []middlewareFunc } -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 := config{ router: chi.NewRouter(), logger: logger, @@ -95,7 +95,7 @@ func withDefaultMiddleware() Option { return func(c *config) { if !c.customRouter { defaults := []middlewareFunc{ - middlewares.APIVersionMiddleware{LoggerFactory: c.logger}.ValidateAPIVersionHdr, + middlewares.APIVersionMiddleware{Logger: c.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..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 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..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()) }) }) }) From 87497e4a8f815a04d2c42f96e89690115d25a3ef Mon Sep 17 00:00:00 2001 From: George Blue Date: Tue, 6 Feb 2024 15:04:10 +0000 Subject: [PATCH 2/6] chore: wrap slog.Logger to reduce boilerplate --- domain/apiresponses/failure_responses.go | 8 +-- domain/apiresponses/failure_responses_test.go | 16 +++-- failure_response_test.go | 16 +++-- handlers/api_handler.go | 6 +- handlers/bind.go | 26 +++---- handlers/catalog.go | 10 +-- handlers/deprovision.go | 20 +++--- handlers/get_binding.go | 17 ++--- handlers/get_instance.go | 17 ++--- handlers/last_binding_operation.go | 21 +++--- handlers/last_operation.go | 19 ++---- handlers/provision.go | 24 +++---- handlers/unbind.go | 20 ++---- handlers/update.go | 20 ++---- internal/blog/blog.go | 68 +++++++++++++++++++ internal/blog/blog_suite_test.go | 13 ++++ internal/blog/blog_test.go | 55 +++++++++++++++ internal/logutil/error.go | 7 -- internal/logutil/join.go | 7 -- middlewares/api_version_header.go | 13 +--- utils/context.go | 12 ---- utils/context_test.go | 40 ----------- 22 files changed, 236 insertions(+), 219 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 delete mode 100644 internal/logutil/error.go delete mode 100644 internal/logutil/join.go diff --git a/domain/apiresponses/failure_responses.go b/domain/apiresponses/failure_responses.go index 8d171225..b657defc 100644 --- a/domain/apiresponses/failure_responses.go +++ b/domain/apiresponses/failure_responses.go @@ -1,11 +1,9 @@ package apiresponses import ( + "errors" "fmt" - "log/slog" "net/http" - - "github.com/pivotal-cf/brokerapi/v10/internal/logutil" ) // FailureResponse can be returned from any of the `ServiceBroker` interface methods @@ -44,10 +42,10 @@ func (f *FailureResponse) ErrorResponse() interface{} { } } -func (f *FailureResponse) ValidatedStatusCode(prefix string, logger *slog.Logger) int { +func (f *FailureResponse) ValidatedStatusCode(logger interface{ Error(string, error) }) int { if f.statusCode < 400 || 600 <= f.statusCode { if logger != nil { - 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.")) + logger.Error("validating-status-code", errors.New("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) } return http.StatusInternalServerError } diff --git a/domain/apiresponses/failure_responses_test.go b/domain/apiresponses/failure_responses_test.go index 738dc314..edc6b3fc 100644 --- a/domain/apiresponses/failure_responses_test.go +++ b/domain/apiresponses/failure_responses_test.go @@ -1,6 +1,7 @@ package apiresponses_test import ( + "context" "errors" "log/slog" "net/http" @@ -9,6 +10,7 @@ import ( . "github.com/onsi/gomega" "github.com/onsi/gomega/gbytes" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" + "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) var _ = Describe("FailureResponse", func() { @@ -46,7 +48,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) @@ -62,7 +64,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())) }) @@ -71,25 +73,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 := slog.New(slog.NewJSONHandler(log, nil)) + logger := blog.New(context.TODO(), slog.New(slog.NewJSONHandler(log, nil)), "prefix") 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 3a78044b..4c2ee8f1 100644 --- a/failure_response_test.go +++ b/failure_response_test.go @@ -16,6 +16,7 @@ package brokerapi_test import ( + "context" "errors" "log/slog" "net/http" @@ -25,6 +26,7 @@ import ( "github.com/onsi/gomega/gbytes" "github.com/pivotal-cf/brokerapi/v10" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" + "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) var _ = Describe("FailureResponse", func() { @@ -62,7 +64,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) @@ -78,7 +80,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())) }) @@ -87,25 +89,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 := slog.New(slog.NewJSONHandler(log, nil)) + logger := blog.New(context.TODO(), slog.New(slog.NewJSONHandler(log, nil)), "prefix") 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/handlers/api_handler.go b/handlers/api_handler.go index 192eaa4e..fc39f30b 100644 --- a/handlers/api_handler.go +++ b/handlers/api_handler.go @@ -8,17 +8,13 @@ import ( "net/http" "github.com/pivotal-cf/brokerapi/v10/domain" - "github.com/pivotal-cf/brokerapi/v10/internal/logutil" ) const ( invalidServiceDetailsErrorKey = "invalid-service-details" - instanceIDLogKey = "instance-id" serviceIdMissingKey = "service-id-missing" planIdMissingKey = "plan-id-missing" unknownErrorKey = "unknown-error" - - bindingIDLogKey = "binding-id" ) var ( @@ -48,7 +44,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", logutil.Error(err), slog.Int("status", status), slog.Any("response", response)) + h.logger.Error("encoding response", slog.Any("error", err), slog.Int("status", status), slog.Any("response", response)) } } diff --git a/handlers/bind.go b/handlers/bind.go index 9d83c290..6d0a5162 100644 --- a/handlers/bind.go +++ b/handlers/bind.go @@ -3,30 +3,26 @@ package handlers import ( "encoding/json" "fmt" - "log/slog" "net/http" + "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/internal/logutil" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const ( bindLogKey = "bind" - invalidBindDetailsErrorKey = "bind.invalid-bind-details" + 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.With(append( - []any{slog.String(instanceIDLogKey, instanceID), slog.String(bindingIDLogKey, bindingID)}, - utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., - )...) + logger := blog.New(req.Context(), h.logger, bindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) version := getAPIVersion(req) asyncAllowed := false @@ -38,7 +34,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, logutil.Error(err)) + logger.Error(invalidBindDetailsErrorKey, err) h.respond(w, http.StatusUnprocessableEntity, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -46,7 +42,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { } if details.ServiceID == "" { - logger.Error(logutil.Join(bindLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) + logger.Error(serviceIdMissingKey, serviceIdError) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) @@ -54,7 +50,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { } if details.PlanID == "" { - logger.Error(logutil.Join(bindLogKey, planIdMissingKey), logutil.Error(planIdError)) + logger.Error(planIdMissingKey, planIdError) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: planIdError.Error(), }) @@ -65,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(bindLogKey, logger) + statusCode := err.ValidatedStatusCode(logger) errorResponse := err.ErrorResponse() if err == apiresponses.ErrInstanceDoesNotExist { // work around ErrInstanceDoesNotExist having different pre-refactor behaviour to other actions @@ -74,10 +70,10 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { } statusCode = http.StatusNotFound } - logger.Error(logutil.Join(bindLogKey, err.LoggerAction()), logutil.Error(err)) + logger.Error(err.LoggerAction(), err) h.respond(w, statusCode, requestId, errorResponse) default: - logger.Error(logutil.Join(bindLogKey, unknownErrorKey), logutil.Error(err)) + logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -109,7 +105,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(logutil.Join(bindLogKey, unknownErrorKey), logutil.Error(err)) + logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{Description: err.Error()}) return } diff --git a/handlers/catalog.go b/handlers/catalog.go index bfe6d5aa..8788d0a0 100644 --- a/handlers/catalog.go +++ b/handlers/catalog.go @@ -4,24 +4,24 @@ import ( "fmt" "net/http" + "github.com/pivotal-cf/brokerapi/v10/internal/blog" + "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" - "github.com/pivotal-cf/brokerapi/v10/internal/logutil" "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.With(utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)...) + logger := blog.New(req.Context(), h.logger, getCatalogLogKey) 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(logutil.Join(getCatalogLogKey, err.LoggerAction()), logutil.Error(err)) - h.respond(w, err.ValidatedStatusCode(getCatalogLogKey, logger), requestId, err.ErrorResponse()) + logger.Error(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) default: logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ diff --git a/handlers/deprovision.go b/handlers/deprovision.go index 318bfc44..dabfbfbe 100644 --- a/handlers/deprovision.go +++ b/handlers/deprovision.go @@ -2,15 +2,14 @@ package handlers import ( "fmt" - "log/slog" "net/http" + "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/internal/logutil" "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/utils" ) const deprovisionLogKey = "deprovision" @@ -18,10 +17,7 @@ const deprovisionLogKey = "deprovision" func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := h.logger.With(append( - []any{slog.String(instanceIDLogKey, instanceID)}, - utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., - )...) + logger := blog.New(req.Context(), h.logger, deprovisionLogKey, blog.InstanceID(instanceID)) details := domain.DeprovisionDetails{ PlanID: req.FormValue("plan_id"), @@ -35,7 +31,7 @@ func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) - logger.Error(logutil.Join(deprovisionLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) + logger.Error(serviceIdMissingKey, serviceIdError) return } @@ -43,7 +39,7 @@ func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: planIdError.Error(), }) - logger.Error(logutil.Join(deprovisionLogKey, planIdMissingKey), logutil.Error(planIdError)) + logger.Error(planIdMissingKey, planIdError) return } @@ -53,10 +49,10 @@ func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(logutil.Join(deprovisionLogKey, err.LoggerAction()), logutil.Error(err)) - h.respond(w, err.ValidatedStatusCode(deprovisionLogKey, logger), requestId, err.ErrorResponse()) + logger.Error(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) default: - logger.Error(logutil.Join(deprovisionLogKey, unknownErrorKey), logutil.Error(err)) + logger.Error(unknownErrorKey, 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 8bf61ee6..88a76a5e 100644 --- a/handlers/get_binding.go +++ b/handlers/get_binding.go @@ -3,16 +3,14 @@ package handlers import ( "errors" "fmt" - "log/slog" "net/http" - "github.com/pivotal-cf/brokerapi/v10/internal/logutil" + "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 getBindLogKey = "getBinding" @@ -21,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.With(append( - []any{slog.String(instanceIDLogKey, instanceID), slog.String(bindingIDLogKey, bindingID)}, - utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., - )...) + logger := blog.New(req.Context(), h.logger, getBindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -34,7 +29,7 @@ func (h APIHandler) GetBinding(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusPreconditionFailed, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) - logger.Error(logutil.Join(getBindLogKey, middlewares.ApiVersionInvalidKey), logutil.Error(err)) + logger.Error(middlewares.ApiVersionInvalidKey, err) return } @@ -47,10 +42,10 @@ func (h APIHandler) GetBinding(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(logutil.Join(getBindLogKey, err.LoggerAction()), logutil.Error(err)) - h.respond(w, err.ValidatedStatusCode(getBindLogKey, logger), requestId, err.ErrorResponse()) + logger.Error(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) default: - logger.Error(logutil.Join(getBindLogKey, unknownErrorKey), logutil.Error(err)) + logger.Error(unknownErrorKey, 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 052fd1a7..2ad1bf69 100644 --- a/handlers/get_instance.go +++ b/handlers/get_instance.go @@ -3,16 +3,14 @@ package handlers import ( "errors" "fmt" - "log/slog" "net/http" - "github.com/pivotal-cf/brokerapi/v10/internal/logutil" + "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" @@ -20,10 +18,7 @@ const getInstanceLogKey = "getInstance" func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := h.logger.With(append( - []any{slog.String(instanceIDLogKey, instanceID)}, - utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., - )...) + logger := blog.New(req.Context(), h.logger, getInstanceLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -33,7 +28,7 @@ func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusPreconditionFailed, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) - logger.Error(logutil.Join(getInstanceLogKey, middlewares.ApiVersionInvalidKey), logutil.Error(err)) + logger.Error(middlewares.ApiVersionInvalidKey, err) return } @@ -46,10 +41,10 @@ func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(logutil.Join(getInstanceLogKey, err.LoggerAction()), logutil.Error(err)) - h.respond(w, err.ValidatedStatusCode(getInstanceLogKey, logger), requestId, err.ErrorResponse()) + logger.Error(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) default: - logger.Error(logutil.Join(getInstanceLogKey, unknownErrorKey), logutil.Error(err)) + logger.Error(unknownErrorKey, 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 6e298e44..8c863472 100644 --- a/handlers/last_binding_operation.go +++ b/handlers/last_binding_operation.go @@ -6,13 +6,11 @@ import ( "log/slog" "net/http" - "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" + "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" @@ -26,10 +24,7 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques OperationData: req.FormValue("operation"), } - logger := h.logger.With(append( - []any{slog.String(instanceIDLogKey, instanceID)}, - utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., - )...) + logger := blog.New(req.Context(), h.logger, lastBindingOperationLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -39,20 +34,20 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques h.respond(w, http.StatusPreconditionFailed, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) - logger.Error(logutil.Join(lastBindingOperationLogKey, middlewares.ApiVersionInvalidKey), logutil.Error(err)) + logger.Error(middlewares.ApiVersionInvalidKey, err) return } - logger.Info(logutil.Join(lastBindingOperationLogKey, "starting-check-for-binding-operation")) + logger.Info("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(logutil.Join(lastBindingOperationLogKey, err.LoggerAction()), logutil.Error(err)) - h.respond(w, err.ValidatedStatusCode(lastBindingOperationLogKey, logger), requestId, err.ErrorResponse()) + logger.Error(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) default: - logger.Error(logutil.Join(lastBindingOperationLogKey, unknownErrorKey), logutil.Error(err)) + logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -60,7 +55,7 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques return } - logger.Info(logutil.Join(lastBindingOperationLogKey, "done-check-for-binding-operation"), slog.Any("state", lastOperation.State)) + logger.Info("done-check-for-binding-operation", slog.Any("state", lastOperation.State)) lastOperationResponse := apiresponses.LastOperationResponse{ State: lastOperation.State, diff --git a/handlers/last_operation.go b/handlers/last_operation.go index a0c2f75a..17de300b 100644 --- a/handlers/last_operation.go +++ b/handlers/last_operation.go @@ -5,13 +5,11 @@ import ( "log/slog" "net/http" - "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" + "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" @@ -24,12 +22,9 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { OperationData: req.FormValue("operation"), } - logger := h.logger.With(append( - []any{slog.String(instanceIDLogKey, instanceID)}, - utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., - )...) + logger := blog.New(req.Context(), h.logger, lastOperationLogKey, blog.InstanceID(instanceID)) - logger.Info(logutil.Join(lastOperationLogKey, "starting-check-for-operation")) + logger.Info("starting-check-for-operation") requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -37,10 +32,10 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(logutil.Join(lastOperationLogKey, err.LoggerAction()), logutil.Error(err)) - h.respond(w, err.ValidatedStatusCode(lastOperationLogKey, logger), requestId, err.ErrorResponse()) + logger.Error(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) default: - logger.Error(logutil.Join(lastOperationLogKey, unknownErrorKey), logutil.Error(err)) + logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -48,7 +43,7 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { return } - logger.Info(logutil.Join(lastOperationLogKey, "done-check-for-operation"), slog.Any("state", lastOperation.State)) + 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 2d6f31a4..6552a146 100644 --- a/handlers/provision.go +++ b/handlers/provision.go @@ -6,11 +6,10 @@ import ( "log/slog" "net/http" - "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" + "github.com/pivotal-cf/brokerapi/v10/internal/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" "github.com/pivotal-cf/brokerapi/v10/utils" ) @@ -27,16 +26,13 @@ const ( func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := h.logger.With(append( - []any{slog.String(instanceIDLogKey, instanceID)}, - utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., - )...) + logger := blog.New(req.Context(), h.logger, provisionLogKey, blog.InstanceID(instanceID)) 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(logutil.Join(provisionLogKey, invalidServiceDetailsErrorKey), logutil.Error(err)) + logger.Error(invalidServiceDetailsErrorKey, err) h.respond(w, http.StatusUnprocessableEntity, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -44,7 +40,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { } if details.ServiceID == "" { - logger.Error(logutil.Join(provisionLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) + logger.Error(serviceIdMissingKey, serviceIdError) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) @@ -52,7 +48,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { } if details.PlanID == "" { - logger.Error(logutil.Join(provisionLogKey, planIdMissingKey), logutil.Error(planIdError)) + logger.Error(planIdMissingKey, planIdError) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: planIdError.Error(), }) @@ -69,7 +65,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { } } if !valid { - logger.Error(logutil.Join(provisionLogKey, invalidServiceID), logutil.Error(invalidServiceIDError)) + logger.Error(invalidServiceID, invalidServiceIDError) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: invalidServiceIDError.Error(), }) @@ -87,7 +83,7 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { } } if !valid { - logger.Error(logutil.Join(provisionLogKey, invalidPlanID), logutil.Error(invalidPlanIDError)) + logger.Error(invalidPlanID, invalidPlanIDError) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: invalidPlanIDError.Error(), }) @@ -103,10 +99,10 @@ func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(logutil.Join(provisionLogKey, err.LoggerAction()), logutil.Error(err)) - h.respond(w, err.ValidatedStatusCode(provisionLogKey, logger), requestId, err.ErrorResponse()) + logger.Error(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) default: - logger.Error(logutil.Join(provisionLogKey, unknownErrorKey), logutil.Error(err)) + logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) diff --git a/handlers/unbind.go b/handlers/unbind.go index 9944fddc..0ae0bdc2 100644 --- a/handlers/unbind.go +++ b/handlers/unbind.go @@ -2,16 +2,13 @@ package handlers import ( "fmt" - "log/slog" "net/http" - "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" + "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" @@ -20,10 +17,7 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := h.logger.With(append( - []any{slog.String(instanceIDLogKey, instanceID), slog.String(bindingIDLogKey, bindingID)}, - utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., - )...) + logger := blog.New(req.Context(), h.logger, unbindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) @@ -36,7 +30,7 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) - logger.Error(logutil.Join(unbindLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) + logger.Error(serviceIdMissingKey, serviceIdError) return } @@ -44,7 +38,7 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: planIdError.Error(), }) - logger.Error(logutil.Join(unbindLogKey, planIdMissingKey), logutil.Error(planIdError)) + logger.Error(planIdMissingKey, planIdError) return } @@ -53,10 +47,10 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(logutil.Join(unbindLogKey, err.LoggerAction()), logutil.Error(err)) - h.respond(w, err.ValidatedStatusCode(unbindLogKey, logger), requestId, err.ErrorResponse()) + logger.Error(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) default: - logger.Error(logutil.Join(unbindLogKey, unknownErrorKey), logutil.Error(err)) + logger.Error(unknownErrorKey, err) h.respond(w, http.StatusInternalServerError, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) diff --git a/handlers/update.go b/handlers/update.go index 02c7a96c..3cb5ede1 100644 --- a/handlers/update.go +++ b/handlers/update.go @@ -3,17 +3,14 @@ package handlers import ( "encoding/json" "fmt" - "log/slog" "net/http" "strconv" - "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" + "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" @@ -21,16 +18,13 @@ const updateLogKey = "update" func (h APIHandler) Update(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := h.logger.With(append( - []any{slog.String(instanceIDLogKey, instanceID)}, - utils.ContextAttr(req.Context(), middlewares.CorrelationIDKey, middlewares.RequestIdentityKey)..., - )...) + logger := blog.New(req.Context(), h.logger, 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 { - logger.Error(logutil.Join(updateLogKey, invalidServiceDetailsErrorKey), logutil.Error(err)) + logger.Error(invalidServiceDetailsErrorKey, err) h.respond(w, http.StatusUnprocessableEntity, requestId, apiresponses.ErrorResponse{ Description: err.Error(), }) @@ -38,7 +32,7 @@ func (h APIHandler) Update(w http.ResponseWriter, req *http.Request) { } if details.ServiceID == "" { - logger.Error(logutil.Join(updateLogKey, serviceIdMissingKey), logutil.Error(serviceIdError)) + logger.Error(serviceIdMissingKey, serviceIdError) h.respond(w, http.StatusBadRequest, requestId, apiresponses.ErrorResponse{ Description: serviceIdError.Error(), }) @@ -51,10 +45,10 @@ func (h APIHandler) Update(w http.ResponseWriter, req *http.Request) { if err != nil { switch err := err.(type) { case *apiresponses.FailureResponse: - logger.Error(logutil.Join(updateLogKey, err.LoggerAction()), logutil.Error(err)) - h.respond(w, err.ValidatedStatusCode(updateLogKey, logger), requestId, err.ErrorResponse()) + logger.Error(err.LoggerAction(), err) + h.respond(w, err.ValidatedStatusCode(logger), requestId, err.ErrorResponse()) default: - logger.Error(logutil.Join(updateLogKey, unknownErrorKey), logutil.Error(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..24c8ee07 --- /dev/null +++ b/internal/blog/blog.go @@ -0,0 +1,68 @@ +// Package blog is the brokerapi logger +// BrokerAPI was originally written to use the CloudFoundry Lager logger, and it relied on some idiosyncrasies +// of that logger that are not supported by the (subsequently written) standard library log/slog logger. +// This package is a wrapper around log/slog that adds back the idiosyncrasies of lager, so that the behavior +// is exactly the same. +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(ctx context.Context, logger *slog.Logger, prefix string, supplementary ...slog.Attr) Blog { + var attr []any + for _, s := range supplementary { + attr = append(attr, s) + } + + for _, key := range []middlewares.ContextKey{middlewares.CorrelationIDKey, middlewares.RequestIdentityKey} { + if value := ctx.Value(key); value != nil { + attr = append(attr, slog.Any(string(key), value)) + } + } + + return Blog{ + logger: logger.With(attr...), + prefix: prefix, + } +} + +func (b Blog) Error(message string, err error) { + b.logger.Error(join(b.prefix, message), slog.Any(errorKey, err)) +} + +func (b Blog) Info(message string, attr ...any) { + b.logger.Info(join(b.prefix, message), attr...) +} + +func (b Blog) With(attr ...any) Blog { + b.logger = b.logger.With(attr...) + return b +} + +func InstanceID(instanceID string) slog.Attr { + return slog.String(instanceIDLogKey, instanceID) +} + +func BindingID(bindingID string) slog.Attr { + return slog.String(bindingIDLogKey, bindingID) +} + +func join(s ...string) string { + return strings.Join(s, ".") +} 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..d80fa263 --- /dev/null +++ b/internal/blog/blog_test.go @@ -0,0 +1,55 @@ +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/middlewares" + + "github.com/pivotal-cf/brokerapi/v10/internal/blog" +) + +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(ctx, logger, "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(context.TODO(), logger, "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/internal/logutil/error.go b/internal/logutil/error.go deleted file mode 100644 index 3ef0f962..00000000 --- a/internal/logutil/error.go +++ /dev/null @@ -1,7 +0,0 @@ -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 deleted file mode 100644 index 950588ac..00000000 --- a/internal/logutil/join.go +++ /dev/null @@ -1,7 +0,0 @@ -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 a7960898..4032e123 100644 --- a/middlewares/api_version_header.go +++ b/middlewares/api_version_header.go @@ -21,8 +21,6 @@ import ( "fmt" "log/slog" "net/http" - - "github.com/pivotal-cf/brokerapi/v10/internal/logutil" ) const ( @@ -32,7 +30,7 @@ const ( ) type APIVersionMiddleware struct { - Logger *slog.Logger + Logger interface{ Error(string, ...any) } } type ErrorResponse struct { @@ -43,7 +41,7 @@ func (m APIVersionMiddleware) ValidateAPIVersionHdr(next http.Handler) http.Hand return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { err := checkBrokerAPIVersionHdr(req) if err != nil { - m.Logger.Error(logutil.Join(apiVersionLogKey, ApiVersionInvalidKey), logutil.Error(err)) + m.Logger.Error(fmt.Sprintf("%s.%s", apiVersionLogKey, ApiVersionInvalidKey), slog.Any("error", err)) w.Header().Set("Content-type", "application/json") setBrokerRequestIdentityHeader(req, w) @@ -54,12 +52,7 @@ func (m APIVersionMiddleware) ValidateAPIVersionHdr(next http.Handler) http.Hand Description: err.Error(), } 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), - ) + 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 397a3117..9b76a396 100644 --- a/utils/context.go +++ b/utils/context.go @@ -2,10 +2,8 @@ package utils import ( "context" - "log/slog" "github.com/pivotal-cf/brokerapi/v10/domain" - "github.com/pivotal-cf/brokerapi/v10/middlewares" ) type contextKey string @@ -42,13 +40,3 @@ func RetrieveServicePlanFromContext(ctx context.Context) *domain.ServicePlan { } return nil } - -func ContextAttr(context context.Context, dataKeys ...middlewares.ContextKey) (result []any) { - for _, key := range dataKeys { - if value := context.Value(key); value != nil { - result = append(result, slog.Any(string(key), value)) - } - } - - return -} diff --git a/utils/context_test.go b/utils/context_test.go index 958540da..3270771a 100644 --- a/utils/context_test.go +++ b/utils/context_test.go @@ -2,12 +2,10 @@ package utils_test import ( "context" - "log/slog" . "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" ) @@ -75,42 +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.ContextAttr(ctx, testKey) - Expect(data).To(ConsistOf(slog.Attr{ - Key: string(testKey), - Value: slog.StringValue(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.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.ContextAttr(ctx, testKey) - Expect(data).To(BeEmpty()) - }) - }) - }) }) From 1f81f5e2d777b9b7bc1b5b74b5dba7ee0dd8b14a Mon Sep 17 00:00:00 2001 From: George Blue Date: Tue, 6 Feb 2024 22:19:18 +0000 Subject: [PATCH 3/6] chore: mostly use the blog logger internally Externally we take a *slog.Logger, but internally we wrap this almost everywhere --- api_options.go | 12 +++---- domain/apiresponses/failure_responses.go | 8 ++--- domain/apiresponses/failure_responses_test.go | 19 +++++++---- failure_response_test.go | 19 +++++++---- handlers/api_handler.go | 8 +++-- handlers/bind.go | 2 +- handlers/catalog.go | 4 +-- handlers/deprovision.go | 2 +- handlers/get_binding.go | 2 +- handlers/get_instance.go | 2 +- handlers/last_binding_operation.go | 2 +- handlers/last_operation.go | 2 +- handlers/provision.go | 10 +++--- handlers/unbind.go | 2 +- handlers/update.go | 2 +- internal/blog/blog.go | 34 ++++++++++++------- internal/blog/blog_test.go | 7 ++-- 17 files changed, 74 insertions(+), 63 deletions(-) diff --git a/api_options.go b/api_options.go index becf23af..362127ef 100644 --- a/api_options.go +++ b/api_options.go @@ -30,17 +30,13 @@ type middlewareFunc func(http.Handler) http.Handler type config struct { router chi.Router customRouter bool - logger *slog.Logger additionalMiddleware []middlewareFunc } func NewWithOptions(serviceBroker domain.ServiceBroker, logger *slog.Logger, opts ...Option) http.Handler { - cfg := config{ - router: chi.NewRouter(), - logger: logger, - } + cfg := config{router: chi.NewRouter()} - WithOptions(append(opts, withDefaultMiddleware())...)(&cfg) + WithOptions(append(opts, withDefaultMiddleware(logger))...)(&cfg) attachRoutes(cfg.router, serviceBroker, logger) return cfg.router @@ -91,11 +87,11 @@ func WithEncodedPath() Option { return func(*config) {} } -func withDefaultMiddleware() Option { +func withDefaultMiddleware(logger *slog.Logger) Option { return func(c *config) { if !c.customRouter { defaults := []middlewareFunc{ - middlewares.APIVersionMiddleware{Logger: c.logger}.ValidateAPIVersionHdr, + middlewares.APIVersionMiddleware{Logger: logger}.ValidateAPIVersionHdr, middlewares.AddCorrelationIDToContext, middlewares.AddOriginatingIdentityToContext, middlewares.AddInfoLocationToContext, diff --git a/domain/apiresponses/failure_responses.go b/domain/apiresponses/failure_responses.go index b657defc..1a3cc7c3 100644 --- a/domain/apiresponses/failure_responses.go +++ b/domain/apiresponses/failure_responses.go @@ -4,6 +4,8 @@ import ( "errors" "fmt" "net/http" + + "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) // FailureResponse can be returned from any of the `ServiceBroker` interface methods @@ -42,11 +44,9 @@ func (f *FailureResponse) ErrorResponse() interface{} { } } -func (f *FailureResponse) ValidatedStatusCode(logger interface{ Error(string, error) }) int { +func (f *FailureResponse) ValidatedStatusCode(logger blog.Blog) int { if f.statusCode < 400 || 600 <= f.statusCode { - if logger != nil { - logger.Error("validating-status-code", errors.New("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) - } + logger.Error("validating-status-code", errors.New("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) return http.StatusInternalServerError } return f.statusCode diff --git a/domain/apiresponses/failure_responses_test.go b/domain/apiresponses/failure_responses_test.go index edc6b3fc..66e56f81 100644 --- a/domain/apiresponses/failure_responses_test.go +++ b/domain/apiresponses/failure_responses_test.go @@ -1,7 +1,6 @@ package apiresponses_test import ( - "context" "errors" "log/slog" "net/http" @@ -14,6 +13,12 @@ import ( ) var _ = Describe("FailureResponse", func() { + var fakeLogger blog.Blog + + BeforeEach(func() { + fakeLogger = blog.New(slog.New(slog.NewJSONHandler(GinkgoWriter, nil))) + }) + Describe("ErrorResponse", func() { It("returns a ErrorResponse containing the error message", func() { failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) @@ -48,7 +53,7 @@ var _ = Describe("FailureResponse", func() { newError := failureResponse.AppendErrorMessage("and some more details") Expect(newError.Error()).To(Equal("my error message and some more details")) - Expect(newError.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) errorResponse, typeCast := newError.ErrorResponse().(apiresponses.ErrorResponse) @@ -64,7 +69,7 @@ var _ = Describe("FailureResponse", func() { newError := failureResponse.AppendErrorMessage("and some more details") Expect(newError.Error()).To(Equal("my error message and some more details")) - Expect(newError.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) Expect(newError.ErrorResponse()).To(Equal(failureResponse.ErrorResponse())) }) @@ -73,23 +78,23 @@ var _ = Describe("FailureResponse", func() { Describe("ValidatedStatusCode", func() { It("returns the status code that was passed in", func() { failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) - Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) }) It("when error key is provided it returns the status code that was passed in", func() { failureResponse := apiresponses.NewFailureResponseBuilder(errors.New("my error message"), http.StatusForbidden, "log-key").WithErrorKey("error key").Build() - Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) }) Context("when the status code is invalid", func() { It("returns 500", func() { failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), 600, "log-key")) - Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusInternalServerError)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusInternalServerError)) }) It("logs that the status has been changed", func() { log := gbytes.NewBuffer() - logger := blog.New(context.TODO(), slog.New(slog.NewJSONHandler(log, nil)), "prefix") + logger := blog.New(slog.New(slog.NewJSONHandler(log, nil))) failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), 600, "log-key")) failureResponse.ValidatedStatusCode(logger) Expect(log).To(gbytes.Say("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) diff --git a/failure_response_test.go b/failure_response_test.go index 4c2ee8f1..e3cc163f 100644 --- a/failure_response_test.go +++ b/failure_response_test.go @@ -16,7 +16,6 @@ package brokerapi_test import ( - "context" "errors" "log/slog" "net/http" @@ -30,6 +29,12 @@ import ( ) var _ = Describe("FailureResponse", func() { + var fakeLogger blog.Blog + + BeforeEach(func() { + fakeLogger = blog.New(slog.New(slog.NewJSONHandler(GinkgoWriter, nil))) + }) + Describe("ErrorResponse", func() { It("returns a ErrorResponse containing the error message", func() { failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) @@ -64,7 +69,7 @@ var _ = Describe("FailureResponse", func() { newError := failureResponse.AppendErrorMessage("and some more details") Expect(newError.Error()).To(Equal("my error message and some more details")) - Expect(newError.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) errorResponse, typeCast := newError.ErrorResponse().(brokerapi.ErrorResponse) @@ -80,7 +85,7 @@ var _ = Describe("FailureResponse", func() { newError := failureResponse.AppendErrorMessage("and some more details") Expect(newError.Error()).To(Equal("my error message and some more details")) - Expect(newError.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) + Expect(newError.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) Expect(newError.LoggerAction()).To(Equal(failureResponse.LoggerAction())) Expect(newError.ErrorResponse()).To(Equal(failureResponse.ErrorResponse())) }) @@ -89,23 +94,23 @@ var _ = Describe("FailureResponse", func() { Describe("ValidatedStatusCode", func() { It("returns the status code that was passed in", func() { failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) - Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) }) It("when error key is provided it returns the status code that was passed in", func() { failureResponse := brokerapi.NewFailureResponseBuilder(errors.New("my error message"), http.StatusForbidden, "log-key").WithErrorKey("error key").Build() - Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusForbidden)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusForbidden)) }) Context("when the status code is invalid", func() { It("returns 500", func() { failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), 600, "log-key")) - Expect(failureResponse.ValidatedStatusCode(nil)).To(Equal(http.StatusInternalServerError)) + Expect(failureResponse.ValidatedStatusCode(fakeLogger)).To(Equal(http.StatusInternalServerError)) }) It("logs that the status has been changed", func() { log := gbytes.NewBuffer() - logger := blog.New(context.TODO(), slog.New(slog.NewJSONHandler(log, nil)), "prefix") + logger := blog.New(slog.New(slog.NewJSONHandler(log, nil))) failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), 600, "log-key")) failureResponse.ValidatedStatusCode(logger) Expect(log).To(gbytes.Say("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) diff --git a/handlers/api_handler.go b/handlers/api_handler.go index fc39f30b..4bfbdec7 100644 --- a/handlers/api_handler.go +++ b/handlers/api_handler.go @@ -7,6 +7,8 @@ import ( "log/slog" "net/http" + "github.com/pivotal-cf/brokerapi/v10/internal/blog" + "github.com/pivotal-cf/brokerapi/v10/domain" ) @@ -26,11 +28,11 @@ var ( type APIHandler struct { serviceBroker domain.ServiceBroker - logger *slog.Logger + logger blog.Blog } func NewApiHandler(broker domain.ServiceBroker, logger *slog.Logger) APIHandler { - return APIHandler{broker, logger} + return APIHandler{serviceBroker: broker, logger: blog.New(logger)} } func (h APIHandler) respond(w http.ResponseWriter, status int, requestIdentity string, response interface{}) { @@ -44,7 +46,7 @@ func (h APIHandler) respond(w http.ResponseWriter, status int, requestIdentity s encoder.SetEscapeHTML(false) err := encoder.Encode(response) if err != nil { - h.logger.Error("encoding response", slog.Any("error", err), slog.Int("status", status), slog.Any("response", response)) + h.logger.Error("encoding response", err, slog.Int("status", status), slog.Any("response", response)) } } diff --git a/handlers/bind.go b/handlers/bind.go index 6d0a5162..b8a900bf 100644 --- a/handlers/bind.go +++ b/handlers/bind.go @@ -22,7 +22,7 @@ func (h APIHandler) Bind(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := blog.New(req.Context(), h.logger, bindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) + logger := h.logger.Session(req.Context(), bindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) version := getAPIVersion(req) asyncAllowed := false diff --git a/handlers/catalog.go b/handlers/catalog.go index 8788d0a0..fc0917d7 100644 --- a/handlers/catalog.go +++ b/handlers/catalog.go @@ -4,8 +4,6 @@ import ( "fmt" "net/http" - "github.com/pivotal-cf/brokerapi/v10/internal/blog" - "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" "github.com/pivotal-cf/brokerapi/v10/middlewares" ) @@ -13,7 +11,7 @@ import ( const getCatalogLogKey = "getCatalog" func (h *APIHandler) Catalog(w http.ResponseWriter, req *http.Request) { - logger := blog.New(req.Context(), h.logger, getCatalogLogKey) + logger := h.logger.Session(req.Context(), getCatalogLogKey) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) services, err := h.serviceBroker.Services(req.Context()) diff --git a/handlers/deprovision.go b/handlers/deprovision.go index dabfbfbe..a56c505d 100644 --- a/handlers/deprovision.go +++ b/handlers/deprovision.go @@ -17,7 +17,7 @@ const deprovisionLogKey = "deprovision" func (h APIHandler) Deprovision(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := blog.New(req.Context(), h.logger, deprovisionLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), deprovisionLogKey, blog.InstanceID(instanceID)) details := domain.DeprovisionDetails{ PlanID: req.FormValue("plan_id"), diff --git a/handlers/get_binding.go b/handlers/get_binding.go index 88a76a5e..77342f01 100644 --- a/handlers/get_binding.go +++ b/handlers/get_binding.go @@ -19,7 +19,7 @@ func (h APIHandler) GetBinding(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := blog.New(req.Context(), h.logger, getBindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) + logger := h.logger.Session(req.Context(), getBindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/get_instance.go b/handlers/get_instance.go index 2ad1bf69..64b608a9 100644 --- a/handlers/get_instance.go +++ b/handlers/get_instance.go @@ -18,7 +18,7 @@ const getInstanceLogKey = "getInstance" func (h APIHandler) GetInstance(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := blog.New(req.Context(), h.logger, getInstanceLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), getInstanceLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/last_binding_operation.go b/handlers/last_binding_operation.go index 8c863472..38fcc25a 100644 --- a/handlers/last_binding_operation.go +++ b/handlers/last_binding_operation.go @@ -24,7 +24,7 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques OperationData: req.FormValue("operation"), } - logger := blog.New(req.Context(), h.logger, lastBindingOperationLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), lastBindingOperationLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/last_operation.go b/handlers/last_operation.go index 17de300b..7abc4e64 100644 --- a/handlers/last_operation.go +++ b/handlers/last_operation.go @@ -22,7 +22,7 @@ func (h APIHandler) LastOperation(w http.ResponseWriter, req *http.Request) { OperationData: req.FormValue("operation"), } - logger := blog.New(req.Context(), h.logger, lastOperationLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), lastOperationLogKey, blog.InstanceID(instanceID)) logger.Info("starting-check-for-operation") diff --git a/handlers/provision.go b/handlers/provision.go index 6552a146..d610cb01 100644 --- a/handlers/provision.go +++ b/handlers/provision.go @@ -15,18 +15,16 @@ import ( ) const ( - provisionLogKey = "provision" - + provisionLogKey = "provision" instanceDetailsLogKey = "instance-details" - - invalidServiceID = "invalid-service-id" - invalidPlanID = "invalid-plan-id" + invalidServiceID = "invalid-service-id" + invalidPlanID = "invalid-plan-id" ) func (h *APIHandler) Provision(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := blog.New(req.Context(), h.logger, provisionLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), provisionLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/unbind.go b/handlers/unbind.go index 0ae0bdc2..0a2b3022 100644 --- a/handlers/unbind.go +++ b/handlers/unbind.go @@ -17,7 +17,7 @@ func (h APIHandler) Unbind(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") bindingID := chi.URLParam(req, "binding_id") - logger := blog.New(req.Context(), h.logger, unbindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) + logger := h.logger.Session(req.Context(), unbindLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/handlers/update.go b/handlers/update.go index 3cb5ede1..b1ccbf6f 100644 --- a/handlers/update.go +++ b/handlers/update.go @@ -18,7 +18,7 @@ const updateLogKey = "update" func (h APIHandler) Update(w http.ResponseWriter, req *http.Request) { instanceID := chi.URLParam(req, "instance_id") - logger := blog.New(req.Context(), h.logger, updateLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), updateLogKey, blog.InstanceID(instanceID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey)) diff --git a/internal/blog/blog.go b/internal/blog/blog.go index 24c8ee07..758a4064 100644 --- a/internal/blog/blog.go +++ b/internal/blog/blog.go @@ -1,8 +1,8 @@ // Package blog is the brokerapi logger -// BrokerAPI was originally written to use the CloudFoundry Lager logger, and it relied on some idiosyncrasies -// of that logger that are not supported by the (subsequently written) standard library log/slog logger. -// This package is a wrapper around log/slog that adds back the idiosyncrasies of lager, so that the behavior -// is exactly the same. +// BrokerAPI was originally written to use the CloudFoundry Lager logger (https://github.com/cloudfoundry/lager), +// and it relied on some idiosyncrasies of that logger that are not found in the (subsequently written) +// Go standard library log/slog logger. This package is a wrapper around log/slog that adds back the +// idiosyncrasies of lager, minimizes boilerplate code, and keeps the behavior as similar as possible. package blog import ( @@ -24,12 +24,11 @@ type Blog struct { prefix string } -func New(ctx context.Context, logger *slog.Logger, prefix string, supplementary ...slog.Attr) Blog { - var attr []any - for _, s := range supplementary { - attr = append(attr, s) - } +func New(logger *slog.Logger) Blog { + return Blog{logger: logger} +} +func (b Blog) Session(ctx context.Context, prefix string, attr ...any) Blog { for _, key := range []middlewares.ContextKey{middlewares.CorrelationIDKey, middlewares.RequestIdentityKey} { if value := ctx.Value(key); value != nil { attr = append(attr, slog.Any(string(key), value)) @@ -37,13 +36,13 @@ func New(ctx context.Context, logger *slog.Logger, prefix string, supplementary } return Blog{ - logger: logger.With(attr...), - prefix: prefix, + logger: b.logger.With(attr...), + prefix: appendPrefix(b.prefix, prefix), } } -func (b Blog) Error(message string, err error) { - b.logger.Error(join(b.prefix, message), slog.Any(errorKey, err)) +func (b Blog) Error(message string, err error, attr ...any) { + b.logger.Error(join(b.prefix, message), append([]any{slog.Any(errorKey, err)}, attr...)...) } func (b Blog) Info(message string, attr ...any) { @@ -66,3 +65,12 @@ func BindingID(bindingID string) slog.Attr { func join(s ...string) string { return strings.Join(s, ".") } + +func appendPrefix(existing, addition string) string { + switch existing { + case "": + return addition + default: + return join(existing, addition) + } +} diff --git a/internal/blog/blog_test.go b/internal/blog/blog_test.go index d80fa263..7c666c72 100644 --- a/internal/blog/blog_test.go +++ b/internal/blog/blog_test.go @@ -8,9 +8,8 @@ import ( . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" "github.com/onsi/gomega/gbytes" - "github.com/pivotal-cf/brokerapi/v10/middlewares" - "github.com/pivotal-cf/brokerapi/v10/internal/blog" + "github.com/pivotal-cf/brokerapi/v10/middlewares" ) var _ = Describe("Context data", func() { @@ -28,7 +27,7 @@ var _ = Describe("Context data", func() { buffer := gbytes.NewBuffer() logger := slog.New(slog.NewJSONHandler(buffer, nil)) - blog.New(ctx, logger, "prefix").Info("hello") + blog.New(logger).Session(ctx, "prefix").Info("hello") var receiver map[string]any Expect(json.Unmarshal(buffer.Contents(), &receiver)).To(Succeed()) @@ -43,7 +42,7 @@ var _ = Describe("Context data", func() { buffer := gbytes.NewBuffer() logger := slog.New(slog.NewJSONHandler(buffer, nil)) - blog.New(context.TODO(), logger, "prefix").Info("hello") + blog.New(logger).Session(context.TODO(), "prefix").Info("hello") var receiver map[string]any Expect(json.Unmarshal(buffer.Contents(), &receiver)).To(Succeed()) From c5429835ca8c80e13dd9b7ca068fd583e439ad52 Mon Sep 17 00:00:00 2001 From: George Blue Date: Wed, 7 Feb 2024 18:10:52 +0000 Subject: [PATCH 4/6] feat: ensure public API consistently uses slog.Logger Previously some of the public API had been altered to take the (internal) Blog logger. This is not correct, so the public API should now consistely take a *slog.Logger, and a Blog logger now implements the slog.Handler interface so can easily be converted to a slog.Logger. --- domain/apiresponses/failure_responses.go | 10 ++--- domain/apiresponses/failure_responses_test.go | 19 +++----- failure_response_test.go | 19 +++----- handlers/bind.go | 3 +- handlers/catalog.go | 3 +- handlers/deprovision.go | 3 +- handlers/get_binding.go | 3 +- handlers/get_instance.go | 3 +- handlers/last_binding_operation.go | 2 +- handlers/last_operation.go | 2 +- handlers/provision.go | 2 +- handlers/unbind.go | 3 +- handlers/update.go | 3 +- internal/blog/blog.go | 44 +++++++++++++++++++ middlewares/api_version_header.go | 2 +- 15 files changed, 79 insertions(+), 42 deletions(-) diff --git a/domain/apiresponses/failure_responses.go b/domain/apiresponses/failure_responses.go index 1a3cc7c3..6be2669f 100644 --- a/domain/apiresponses/failure_responses.go +++ b/domain/apiresponses/failure_responses.go @@ -1,11 +1,9 @@ package apiresponses import ( - "errors" "fmt" + "log/slog" "net/http" - - "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) // FailureResponse can be returned from any of the `ServiceBroker` interface methods @@ -44,9 +42,11 @@ func (f *FailureResponse) ErrorResponse() interface{} { } } -func (f *FailureResponse) ValidatedStatusCode(logger blog.Blog) int { +func (f *FailureResponse) ValidatedStatusCode(logger *slog.Logger) int { if f.statusCode < 400 || 600 <= f.statusCode { - logger.Error("validating-status-code", errors.New("Invalid failure http response code: 600, expected 4xx or 5xx, returning internal server error: 500.")) + if logger != nil { + 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 } return f.statusCode diff --git a/domain/apiresponses/failure_responses_test.go b/domain/apiresponses/failure_responses_test.go index 66e56f81..ff89664f 100644 --- a/domain/apiresponses/failure_responses_test.go +++ b/domain/apiresponses/failure_responses_test.go @@ -9,16 +9,9 @@ import ( . "github.com/onsi/gomega" "github.com/onsi/gomega/gbytes" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" - "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) var _ = Describe("FailureResponse", func() { - var fakeLogger blog.Blog - - BeforeEach(func() { - fakeLogger = blog.New(slog.New(slog.NewJSONHandler(GinkgoWriter, nil))) - }) - Describe("ErrorResponse", func() { It("returns a ErrorResponse containing the error message", func() { failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) @@ -53,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(fakeLogger)).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) @@ -69,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(fakeLogger)).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())) }) @@ -78,23 +71,23 @@ var _ = Describe("FailureResponse", func() { Describe("ValidatedStatusCode", func() { It("returns the status code that was passed in", func() { failureResponse := asFailureResponse(apiresponses.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) - Expect(failureResponse.ValidatedStatusCode(fakeLogger)).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(fakeLogger)).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(fakeLogger)).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 := blog.New(slog.New(slog.NewJSONHandler(log, nil))) + 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 e3cc163f..5ec9cd28 100644 --- a/failure_response_test.go +++ b/failure_response_test.go @@ -25,16 +25,9 @@ import ( "github.com/onsi/gomega/gbytes" "github.com/pivotal-cf/brokerapi/v10" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" - "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) var _ = Describe("FailureResponse", func() { - var fakeLogger blog.Blog - - BeforeEach(func() { - fakeLogger = blog.New(slog.New(slog.NewJSONHandler(GinkgoWriter, nil))) - }) - Describe("ErrorResponse", func() { It("returns a ErrorResponse containing the error message", func() { failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) @@ -69,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(fakeLogger)).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) @@ -85,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(fakeLogger)).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())) }) @@ -94,23 +87,23 @@ var _ = Describe("FailureResponse", func() { Describe("ValidatedStatusCode", func() { It("returns the status code that was passed in", func() { failureResponse := asFailureResponse(brokerapi.NewFailureResponse(errors.New("my error message"), http.StatusForbidden, "log-key")) - Expect(failureResponse.ValidatedStatusCode(fakeLogger)).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(fakeLogger)).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(fakeLogger)).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 := blog.New(slog.New(slog.NewJSONHandler(log, nil))) + 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/handlers/bind.go b/handlers/bind.go index b8a900bf..81a7c517 100644 --- a/handlers/bind.go +++ b/handlers/bind.go @@ -3,6 +3,7 @@ package handlers import ( "encoding/json" "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/internal/blog" @@ -61,7 +62,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 fc0917d7..c3ea93aa 100644 --- a/handlers/catalog.go +++ b/handlers/catalog.go @@ -2,6 +2,7 @@ package handlers import ( "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/domain/apiresponses" @@ -19,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/deprovision.go b/handlers/deprovision.go index a56c505d..8e3ca092 100644 --- a/handlers/deprovision.go +++ b/handlers/deprovision.go @@ -2,6 +2,7 @@ package handlers import ( "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/internal/blog" @@ -50,7 +51,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 77342f01..59ecc026 100644 --- a/handlers/get_binding.go +++ b/handlers/get_binding.go @@ -3,6 +3,7 @@ package handlers import ( "errors" "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/internal/blog" @@ -43,7 +44,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 64b608a9..d389a8c3 100644 --- a/handlers/get_instance.go +++ b/handlers/get_instance.go @@ -3,6 +3,7 @@ package handlers import ( "errors" "fmt" + "log/slog" "net/http" "github.com/pivotal-cf/brokerapi/v10/internal/blog" @@ -42,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 38fcc25a..832265cb 100644 --- a/handlers/last_binding_operation.go +++ b/handlers/last_binding_operation.go @@ -45,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{ diff --git a/handlers/last_operation.go b/handlers/last_operation.go index 7abc4e64..2cfe759e 100644 --- a/handlers/last_operation.go +++ b/handlers/last_operation.go @@ -33,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{ diff --git a/handlers/provision.go b/handlers/provision.go index d610cb01..f33afa7f 100644 --- a/handlers/provision.go +++ b/handlers/provision.go @@ -98,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 0a2b3022..40fc7a03 100644 --- a/handlers/unbind.go +++ b/handlers/unbind.go @@ -2,6 +2,7 @@ package handlers import ( "fmt" + "log/slog" "net/http" "github.com/go-chi/chi/v5" @@ -48,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{ diff --git a/handlers/update.go b/handlers/update.go index b1ccbf6f..cb7548fa 100644 --- a/handlers/update.go +++ b/handlers/update.go @@ -3,6 +3,7 @@ package handlers import ( "encoding/json" "fmt" + "log/slog" "net/http" "strconv" @@ -46,7 +47,7 @@ func (h APIHandler) Update(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/internal/blog/blog.go b/internal/blog/blog.go index 758a4064..ae8421e2 100644 --- a/internal/blog/blog.go +++ b/internal/blog/blog.go @@ -3,6 +3,9 @@ // 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 in input. package blog import ( @@ -28,6 +31,8 @@ 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 { @@ -41,23 +46,62 @@ func (b Blog) Session(ctx context.Context, prefix string, attr ...any) Blog { } } +// 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 +} + +func (b Blog) Handle(_ context.Context, record slog.Record) error { + switch record.Level { + case slog.LevelDebug: + b.logger.Debug(join(b.prefix, record.Message)) + case slog.LevelInfo: + b.logger.Info(join(b.prefix, record.Message)) + case slog.LevelWarn: + b.logger.Warn(join(b.prefix, record.Message)) + default: + b.logger.Error(join(b.prefix, record.Message)) + } + + 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) } diff --git a/middlewares/api_version_header.go b/middlewares/api_version_header.go index 4032e123..08df623d 100644 --- a/middlewares/api_version_header.go +++ b/middlewares/api_version_header.go @@ -30,7 +30,7 @@ const ( ) type APIVersionMiddleware struct { - Logger interface{ Error(string, ...any) } + Logger *slog.Logger } type ErrorResponse struct { From ecc0a23a6425ea359cdfc02288388dce9b8afac2 Mon Sep 17 00:00:00 2001 From: George Blue Date: Wed, 7 Feb 2024 22:39:26 +0000 Subject: [PATCH 5/6] chore: tidy up --- domain/apiresponses/failure_responses.go | 2 ++ handlers/api_handler.go | 3 +-- handlers/bind.go | 3 +-- handlers/deprovision.go | 3 +-- handlers/get_binding.go | 3 +-- internal/blog/blog.go | 12 +++++++----- 6 files changed, 13 insertions(+), 13 deletions(-) diff --git a/domain/apiresponses/failure_responses.go b/domain/apiresponses/failure_responses.go index 6be2669f..0dd48951 100644 --- a/domain/apiresponses/failure_responses.go +++ b/domain/apiresponses/failure_responses.go @@ -42,6 +42,8 @@ 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 *slog.Logger) int { if f.statusCode < 400 || 600 <= f.statusCode { if logger != nil { diff --git a/handlers/api_handler.go b/handlers/api_handler.go index 4bfbdec7..ddf94246 100644 --- a/handlers/api_handler.go +++ b/handlers/api_handler.go @@ -7,9 +7,8 @@ import ( "log/slog" "net/http" - "github.com/pivotal-cf/brokerapi/v10/internal/blog" - "github.com/pivotal-cf/brokerapi/v10/domain" + "github.com/pivotal-cf/brokerapi/v10/internal/blog" ) const ( diff --git a/handlers/bind.go b/handlers/bind.go index 81a7c517..00f1b52e 100644 --- a/handlers/bind.go +++ b/handlers/bind.go @@ -6,11 +6,10 @@ import ( "log/slog" "net/http" - "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/internal/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" ) diff --git a/handlers/deprovision.go b/handlers/deprovision.go index 8e3ca092..ed45995f 100644 --- a/handlers/deprovision.go +++ b/handlers/deprovision.go @@ -5,11 +5,10 @@ import ( "log/slog" "net/http" - "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/internal/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" ) diff --git a/handlers/get_binding.go b/handlers/get_binding.go index 59ecc026..e3f986e0 100644 --- a/handlers/get_binding.go +++ b/handlers/get_binding.go @@ -6,11 +6,10 @@ import ( "log/slog" "net/http" - "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/internal/blog" "github.com/pivotal-cf/brokerapi/v10/middlewares" ) diff --git a/internal/blog/blog.go b/internal/blog/blog.go index ae8421e2..714e843f 100644 --- a/internal/blog/blog.go +++ b/internal/blog/blog.go @@ -5,7 +5,7 @@ // 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 in input. +// slog.Logger as an input, and because they are public cannot take a Blog as an input. package blog import ( @@ -81,16 +81,18 @@ 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(join(b.prefix, record.Message)) + b.logger.Debug(msg) case slog.LevelInfo: - b.logger.Info(join(b.prefix, record.Message)) + b.logger.Info(msg) case slog.LevelWarn: - b.logger.Warn(join(b.prefix, record.Message)) + b.logger.Warn(msg) default: - b.logger.Error(join(b.prefix, record.Message)) + b.logger.Error(msg) } return nil From 141d356aecd4ff7fde969a292d9b6a161b6b1001 Mon Sep 17 00:00:00 2001 From: George Blue Date: Tue, 2 Apr 2024 15:10:54 +0100 Subject: [PATCH 6/6] address code review comment --- handlers/last_binding_operation.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/handlers/last_binding_operation.go b/handlers/last_binding_operation.go index 832265cb..9898437e 100644 --- a/handlers/last_binding_operation.go +++ b/handlers/last_binding_operation.go @@ -24,7 +24,7 @@ func (h APIHandler) LastBindingOperation(w http.ResponseWriter, req *http.Reques OperationData: req.FormValue("operation"), } - logger := h.logger.Session(req.Context(), lastBindingOperationLogKey, blog.InstanceID(instanceID)) + logger := h.logger.Session(req.Context(), lastBindingOperationLogKey, blog.InstanceID(instanceID), blog.BindingID(bindingID)) requestId := fmt.Sprintf("%v", req.Context().Value(middlewares.RequestIdentityKey))