From 2b89f38bf2acf65d41e5bd59f76987dfb6e663ce Mon Sep 17 00:00:00 2001 From: Clemens Hoffmann Date: Thu, 12 Dec 2024 13:42:53 +0100 Subject: [PATCH] Introduce disctinct metrics for each route (un)registration case --- metrics/compositereporter.go | 4 +- metrics/fakes/fake_registry_reporter.go | 36 ++++---- metrics/metricsreporter.go | 12 +-- metrics/metricsreporter_test.go | 26 +++--- registry/registry.go | 21 +++-- registry/registry_test.go | 109 +++++++++++++++++++++--- 6 files changed, 150 insertions(+), 58 deletions(-) diff --git a/metrics/compositereporter.go b/metrics/compositereporter.go index 9631893d..56255f3b 100644 --- a/metrics/compositereporter.go +++ b/metrics/compositereporter.go @@ -44,10 +44,10 @@ type RouteRegistryReporter interface { CaptureRouteStats(totalRoutes int, msSinceLastUpdate int64) CaptureRoutesPruned(prunedRoutes uint64) CaptureLookupTime(t time.Duration) - CaptureRegistryMessage(msg ComponentTagged) + CaptureRegistryMessage(msg ComponentTagged, action string) CaptureRouteRegistrationLatency(t time.Duration) UnmuzzleRouteRegistrationLatency() - CaptureUnregistryMessage(msg ComponentTagged) + CaptureUnregistryMessage(msg ComponentTagged, action string) } type CompositeReporter struct { diff --git a/metrics/fakes/fake_registry_reporter.go b/metrics/fakes/fake_registry_reporter.go index 7a8dbd72..3dafcb05 100644 --- a/metrics/fakes/fake_registry_reporter.go +++ b/metrics/fakes/fake_registry_reporter.go @@ -14,10 +14,11 @@ type FakeRouteRegistryReporter struct { captureLookupTimeArgsForCall []struct { arg1 time.Duration } - CaptureRegistryMessageStub func(metrics.ComponentTagged) + CaptureRegistryMessageStub func(metrics.ComponentTagged, string) captureRegistryMessageMutex sync.RWMutex captureRegistryMessageArgsForCall []struct { arg1 metrics.ComponentTagged + arg2 string } CaptureRouteRegistrationLatencyStub func(time.Duration) captureRouteRegistrationLatencyMutex sync.RWMutex @@ -35,10 +36,11 @@ type FakeRouteRegistryReporter struct { captureRoutesPrunedArgsForCall []struct { arg1 uint64 } - CaptureUnregistryMessageStub func(metrics.ComponentTagged) + CaptureUnregistryMessageStub func(metrics.ComponentTagged, string) captureUnregistryMessageMutex sync.RWMutex captureUnregistryMessageArgsForCall []struct { arg1 metrics.ComponentTagged + arg2 string } UnmuzzleRouteRegistrationLatencyStub func() unmuzzleRouteRegistrationLatencyMutex sync.RWMutex @@ -80,16 +82,17 @@ func (fake *FakeRouteRegistryReporter) CaptureLookupTimeArgsForCall(i int) time. return argsForCall.arg1 } -func (fake *FakeRouteRegistryReporter) CaptureRegistryMessage(arg1 metrics.ComponentTagged) { +func (fake *FakeRouteRegistryReporter) CaptureRegistryMessage(arg1 metrics.ComponentTagged, arg2 string) { fake.captureRegistryMessageMutex.Lock() fake.captureRegistryMessageArgsForCall = append(fake.captureRegistryMessageArgsForCall, struct { arg1 metrics.ComponentTagged - }{arg1}) + arg2 string + }{arg1, arg2}) stub := fake.CaptureRegistryMessageStub - fake.recordInvocation("CaptureRegistryMessage", []interface{}{arg1}) + fake.recordInvocation("CaptureRegistryMessage", []interface{}{arg1, arg2}) fake.captureRegistryMessageMutex.Unlock() if stub != nil { - fake.CaptureRegistryMessageStub(arg1) + fake.CaptureRegistryMessageStub(arg1, arg2) } } @@ -99,17 +102,17 @@ func (fake *FakeRouteRegistryReporter) CaptureRegistryMessageCallCount() int { return len(fake.captureRegistryMessageArgsForCall) } -func (fake *FakeRouteRegistryReporter) CaptureRegistryMessageCalls(stub func(metrics.ComponentTagged)) { +func (fake *FakeRouteRegistryReporter) CaptureRegistryMessageCalls(stub func(metrics.ComponentTagged, string)) { fake.captureRegistryMessageMutex.Lock() defer fake.captureRegistryMessageMutex.Unlock() fake.CaptureRegistryMessageStub = stub } -func (fake *FakeRouteRegistryReporter) CaptureRegistryMessageArgsForCall(i int) metrics.ComponentTagged { +func (fake *FakeRouteRegistryReporter) CaptureRegistryMessageArgsForCall(i int) (metrics.ComponentTagged, string) { fake.captureRegistryMessageMutex.RLock() defer fake.captureRegistryMessageMutex.RUnlock() argsForCall := fake.captureRegistryMessageArgsForCall[i] - return argsForCall.arg1 + return argsForCall.arg1, argsForCall.arg2 } func (fake *FakeRouteRegistryReporter) CaptureRouteRegistrationLatency(arg1 time.Duration) { @@ -209,16 +212,17 @@ func (fake *FakeRouteRegistryReporter) CaptureRoutesPrunedArgsForCall(i int) uin return argsForCall.arg1 } -func (fake *FakeRouteRegistryReporter) CaptureUnregistryMessage(arg1 metrics.ComponentTagged) { +func (fake *FakeRouteRegistryReporter) CaptureUnregistryMessage(arg1 metrics.ComponentTagged, arg2 string) { fake.captureUnregistryMessageMutex.Lock() fake.captureUnregistryMessageArgsForCall = append(fake.captureUnregistryMessageArgsForCall, struct { arg1 metrics.ComponentTagged - }{arg1}) + arg2 string + }{arg1, arg2}) stub := fake.CaptureUnregistryMessageStub - fake.recordInvocation("CaptureUnregistryMessage", []interface{}{arg1}) + fake.recordInvocation("CaptureUnregistryMessage", []interface{}{arg1, arg2}) fake.captureUnregistryMessageMutex.Unlock() if stub != nil { - fake.CaptureUnregistryMessageStub(arg1) + fake.CaptureUnregistryMessageStub(arg1, arg2) } } @@ -228,17 +232,17 @@ func (fake *FakeRouteRegistryReporter) CaptureUnregistryMessageCallCount() int { return len(fake.captureUnregistryMessageArgsForCall) } -func (fake *FakeRouteRegistryReporter) CaptureUnregistryMessageCalls(stub func(metrics.ComponentTagged)) { +func (fake *FakeRouteRegistryReporter) CaptureUnregistryMessageCalls(stub func(metrics.ComponentTagged, string)) { fake.captureUnregistryMessageMutex.Lock() defer fake.captureUnregistryMessageMutex.Unlock() fake.CaptureUnregistryMessageStub = stub } -func (fake *FakeRouteRegistryReporter) CaptureUnregistryMessageArgsForCall(i int) metrics.ComponentTagged { +func (fake *FakeRouteRegistryReporter) CaptureUnregistryMessageArgsForCall(i int) (metrics.ComponentTagged, string) { fake.captureUnregistryMessageMutex.RLock() defer fake.captureUnregistryMessageMutex.RUnlock() argsForCall := fake.captureUnregistryMessageArgsForCall[i] - return argsForCall.arg1 + return argsForCall.arg1, argsForCall.arg2 } func (fake *FakeRouteRegistryReporter) UnmuzzleRouteRegistrationLatency() { diff --git a/metrics/metricsreporter.go b/metrics/metricsreporter.go index 79fd6356..1dc7f103 100644 --- a/metrics/metricsreporter.go +++ b/metrics/metricsreporter.go @@ -135,22 +135,22 @@ func (m *MetricsReporter) CaptureRoutesPruned(routesPruned uint64) { m.Batcher.BatchAddCounter("routes_pruned", routesPruned) } -func (m *MetricsReporter) CaptureRegistryMessage(msg ComponentTagged) { +func (m *MetricsReporter) CaptureRegistryMessage(msg ComponentTagged, action string) { var componentName string if msg.Component() == "" { - componentName = "registry_message" + componentName = "registry_message." + action } else { - componentName = "registry_message." + msg.Component() + componentName = "registry_message." + action + "." + msg.Component() } m.Batcher.BatchIncrementCounter(componentName) } -func (m *MetricsReporter) CaptureUnregistryMessage(msg ComponentTagged) { +func (m *MetricsReporter) CaptureUnregistryMessage(msg ComponentTagged, action string) { var componentName string if msg.Component() == "" { - componentName = "unregistry_message" + componentName = "unregistry_message." + action } else { - componentName = "unregistry_message." + msg.Component() + componentName = "unregistry_message." + action + "." + msg.Component() } err := m.Sender.IncrementCounter(componentName) if err != nil { diff --git a/metrics/metricsreporter_test.go b/metrics/metricsreporter_test.go index 5508f172..102f4536 100644 --- a/metrics/metricsreporter_test.go +++ b/metrics/metricsreporter_test.go @@ -448,22 +448,22 @@ var _ = Describe("MetricsReporter", func() { It("sends number of nats messages received from each component", func() { endpoint.Tags = map[string]string{} - metricReporter.CaptureRegistryMessage(endpoint) + metricReporter.CaptureRegistryMessage(endpoint, "some-action") Expect(batcher.BatchIncrementCounterCallCount()).To(Equal(1)) - Expect(batcher.BatchIncrementCounterArgsForCall(0)).To(Equal("registry_message")) + Expect(batcher.BatchIncrementCounterArgsForCall(0)).To(Equal("registry_message.some-action")) }) It("sends number of nats messages received from each component", func() { endpoint.Tags = map[string]string{"component": "uaa"} - metricReporter.CaptureRegistryMessage(endpoint) + metricReporter.CaptureRegistryMessage(endpoint, "some-action") endpoint.Tags = map[string]string{"component": "route-emitter"} - metricReporter.CaptureRegistryMessage(endpoint) + metricReporter.CaptureRegistryMessage(endpoint, "some-action") Expect(batcher.BatchIncrementCounterCallCount()).To(Equal(2)) - Expect(batcher.BatchIncrementCounterArgsForCall(0)).To(Equal("registry_message.uaa")) - Expect(batcher.BatchIncrementCounterArgsForCall(1)).To(Equal("registry_message.route-emitter")) + Expect(batcher.BatchIncrementCounterArgsForCall(0)).To(Equal("registry_message.uaa.some-action")) + Expect(batcher.BatchIncrementCounterArgsForCall(1)).To(Equal("registry_message.route-emitter.some-action")) }) It("sends the total routes", func() { @@ -517,33 +517,33 @@ var _ = Describe("MetricsReporter", func() { BeforeEach(func() { endpoint = new(route.Endpoint) endpoint.Tags = map[string]string{"component": "oauth-server"} - metricReporter.CaptureUnregistryMessage(endpoint) + metricReporter.CaptureUnregistryMessage(endpoint, "some-action") }) It("increments the counter metric", func() { Expect(sender.IncrementCounterCallCount()).To(Equal(1)) - Expect(sender.IncrementCounterArgsForCall(0)).To(Equal("unregistry_message.oauth-server")) + Expect(sender.IncrementCounterArgsForCall(0)).To(Equal("unregistry_message.oauth-server.some-action")) }) It("increments the counter metric for each component unregistered", func() { endpointTwo := new(route.Endpoint) endpointTwo.Tags = map[string]string{"component": "api-server"} - metricReporter.CaptureUnregistryMessage(endpointTwo) + metricReporter.CaptureUnregistryMessage(endpointTwo, "some-action") Expect(sender.IncrementCounterCallCount()).To(Equal(2)) - Expect(sender.IncrementCounterArgsForCall(0)).To(Equal("unregistry_message.oauth-server")) - Expect(sender.IncrementCounterArgsForCall(1)).To(Equal("unregistry_message.api-server")) + Expect(sender.IncrementCounterArgsForCall(0)).To(Equal("unregistry_message.oauth-server.some-action")) + Expect(sender.IncrementCounterArgsForCall(1)).To(Equal("unregistry_message.api-server.some-action")) }) }) Context("when unregister msg with empty component name is incremented", func() { BeforeEach(func() { endpoint = new(route.Endpoint) endpoint.Tags = map[string]string{} - metricReporter.CaptureUnregistryMessage(endpoint) + metricReporter.CaptureUnregistryMessage(endpoint, "some-action") }) It("increments the counter metric", func() { Expect(sender.IncrementCounterCallCount()).To(Equal(1)) - Expect(sender.IncrementCounterArgsForCall(0)).To(Equal("unregistry_message")) + Expect(sender.IncrementCounterArgsForCall(0)).To(Equal("unregistry_message.some-action")) }) }) }) diff --git a/registry/registry.go b/registry/registry.go index 28d61d58..94744c41 100644 --- a/registry/registry.go +++ b/registry/registry.go @@ -87,26 +87,27 @@ func (r *RouteRegistry) Register(uri route.Uri, endpoint *route.Endpoint) { return } - endpointAdded := r.register(uri, endpoint) + endpointPutResult := r.register(uri, endpoint) - r.reporter.CaptureRegistryMessage(endpoint) - - if endpointAdded == route.Added && !endpoint.UpdatedAt.IsZero() { + if endpointPutResult == route.Added && !endpoint.UpdatedAt.IsZero() { r.reporter.CaptureRouteRegistrationLatency(time.Since(endpoint.UpdatedAt)) } - switch endpointAdded { + switch endpointPutResult { case route.Added: + r.reporter.CaptureRegistryMessage(endpoint, "endpoint-added") if r.logger.Enabled(context.Background(), slog.LevelInfo) { - r.logger.Info("endpoint-registered", buildSlogAttrs(uri, endpoint)...) + r.logger.Info("endpoint-added", buildSlogAttrs(uri, endpoint)...) } case route.Updated: + r.reporter.CaptureRegistryMessage(endpoint, "endpoint-updated") if r.logger.Enabled(context.Background(), slog.LevelDebug) { - r.logger.Debug("endpoint-registered", buildSlogAttrs(uri, endpoint)...) + r.logger.Debug("endpoint-updated", buildSlogAttrs(uri, endpoint)...) } default: + r.reporter.CaptureRegistryMessage(endpoint, "endpoint-not-updated") if r.logger.Enabled(context.Background(), slog.LevelDebug) { - r.logger.Debug("endpoint-not-registered", buildSlogAttrs(uri, endpoint)...) + r.logger.Debug("endpoint-not-updated", buildSlogAttrs(uri, endpoint)...) } } } @@ -167,7 +168,6 @@ func (r *RouteRegistry) Unregister(uri route.Uri, endpoint *route.Endpoint) { if !r.endpointInRouterShard(endpoint) { return } - r.reporter.CaptureUnregistryMessage(endpoint) routeKey := uri.RouteKey() endpointUnregisteredResult, pool := r.unregisterEndpoint(routeKey, endpoint) @@ -176,10 +176,12 @@ func (r *RouteRegistry) Unregister(uri route.Uri, endpoint *route.Endpoint) { } switch endpointUnregisteredResult { case route.EndpointUnregistered: + r.reporter.CaptureUnregistryMessage(endpoint, "endpoint-unregistered") if r.logger.Enabled(context.Background(), slog.LevelInfo) { r.logger.Info("endpoint-unregistered", buildSlogAttrs(routeKey, endpoint)...) } case route.EndpointUnmodified: + r.reporter.CaptureUnregistryMessage(endpoint, "endpoint-not-unregistered") if r.logger.Enabled(context.Background(), slog.LevelInfo) { r.logger.Info("endpoint-not-unregistered", buildSlogAttrs(routeKey, endpoint)...) } @@ -188,6 +190,7 @@ func (r *RouteRegistry) Unregister(uri route.Uri, endpoint *route.Endpoint) { routeUnregisteredResult := r.deleteRouteWithoutEndpoint(routeKey, pool) switch routeUnregisteredResult { case route.RouteUnregistered: + r.reporter.CaptureUnregistryMessage(endpoint, "route-unregistered") if r.logger.Enabled(context.Background(), slog.LevelInfo) { r.logger.Info("route-unregistered", slog.Any("uri", routeKey)) } diff --git a/registry/registry_test.go b/registry/registry_test.go index 72917db4..982604ca 100644 --- a/registry/registry_test.go +++ b/registry/registry_test.go @@ -70,9 +70,50 @@ var _ = Describe("RouteRegistry", func() { }) Context("Register", func() { - It("emits message_count metrics", func() { - r.Register("foo", fooEndpoint) - Expect(reporter.CaptureRegistryMessageCallCount()).To(Equal(1)) + Context("when a new endpoint is registered", func() { + It("emits endpoint-registered message_count metrics", func() { + r.Register("foo", fooEndpoint) + Expect(reporter.CaptureRegistryMessageCallCount()).To(Equal(1)) + endpoint1, action1 := reporter.CaptureRegistryMessageArgsForCall(0) + Expect(endpoint1).To(Equal(fooEndpoint)) + Expect(action1).To(Equal("endpoint-registered")) + }) + }) + + Context("when an endpoint is updated", func() { + It("emits endpoint-updated message_count metrics", func() { + modTag1 := models.ModificationTag{Guid: "abc", Index: 0} + endpoint1 := route.NewEndpoint(&route.EndpointOpts{ModificationTag: modTag1}) + modTag2 := models.ModificationTag{Guid: "abc", Index: 1} + endpoint2 := route.NewEndpoint(&route.EndpointOpts{ModificationTag: modTag2}) + r.Register("foo", endpoint1) + r.Register("foo", endpoint2) + Expect(reporter.CaptureRegistryMessageCallCount()).To(Equal(2)) + endpointR1, action1 := reporter.CaptureRegistryMessageArgsForCall(0) + Expect(endpointR1).To(Equal(endpoint1)) + Expect(action1).To(Equal("endpoint-registered")) + endpointR2, action2 := reporter.CaptureRegistryMessageArgsForCall(1) + Expect(endpointR2).To(Equal(endpoint2)) + Expect(action2).To(Equal("endpoint-updated")) + }) + }) + + Context("when modificationTag is older so that the endpoint is not updated", func() { + It("emits endpoint-bot-updated message_count metrics", func() { + modTag1 := models.ModificationTag{Guid: "abc", Index: 1} + endpoint1 := route.NewEndpoint(&route.EndpointOpts{ModificationTag: modTag1}) + modTag2 := models.ModificationTag{Guid: "abc", Index: 0} + endpoint2 := route.NewEndpoint(&route.EndpointOpts{ModificationTag: modTag2}) + r.Register("foo", endpoint1) + r.Register("foo", endpoint2) + Expect(reporter.CaptureRegistryMessageCallCount()).To(Equal(2)) + endpointR1, action1 := reporter.CaptureRegistryMessageArgsForCall(0) + Expect(endpointR1).To(Equal(endpoint1)) + Expect(action1).To(Equal("endpoint-registered")) + endpointR2, action2 := reporter.CaptureRegistryMessageArgsForCall(1) + Expect(endpointR2).To(Equal(endpoint2)) + Expect(action2).To(Equal("endpoint-not-updated")) + }) }) Context("when the endpoint has an UpdatedAt timestamp", func() { @@ -516,25 +557,69 @@ var _ = Describe("RouteRegistry", func() { }) Context("Unregister", func() { - Context("when endpoint has component tagged", func() { + Context("when route is registered", func() { + Context("when endpoint has component tagged", func() { + BeforeEach(func() { + fooEndpoint.Tags = map[string]string{"component": "oauth-server"} + r.Register("foo", fooEndpoint) + }) + It("emits counter metrics for unregister endpoint and route", func() { + r.Unregister("foo", fooEndpoint) + Expect(reporter.CaptureUnregistryMessageCallCount()).To(Equal(2)) + endpoint1, action1 := reporter.CaptureUnregistryMessageArgsForCall(0) + Expect(endpoint1).To(Equal(fooEndpoint)) + Expect(action1).To(Equal("endpoint-unregistered")) + endpoint2, action2 := reporter.CaptureUnregistryMessageArgsForCall(1) + Expect(endpoint2).To(Equal(fooEndpoint)) + Expect(action2).To(Equal("route-unregistered")) + }) + }) + + Context("when endpoint does not have component tag", func() { + BeforeEach(func() { + fooEndpoint.Tags = map[string]string{} + r.Register("foo", fooEndpoint) + }) + It("emits counter metrics for unregister endpoint and route", func() { + r.Unregister("foo", fooEndpoint) + Expect(reporter.CaptureUnregistryMessageCallCount()).To(Equal(2)) + endpoint1, action1 := reporter.CaptureUnregistryMessageArgsForCall(0) + Expect(endpoint1).To(Equal(fooEndpoint)) + Expect(action1).To(Equal("endpoint-unregistered")) + endpoint2, action2 := reporter.CaptureUnregistryMessageArgsForCall(1) + Expect(endpoint2).To(Equal(fooEndpoint)) + Expect(action2).To(Equal("route-unregistered")) + }) + }) + }) + Context("when route has multiple endpoints", func() { BeforeEach(func() { - fooEndpoint.Tags = map[string]string{"component": "oauth-server"} + fooEndpoint.Tags = map[string]string{} + fooEndpoint2 := route.NewEndpoint(&route.EndpointOpts{ + Host: "192.168.1.2", + Tags: map[string]string{ + "runtime": "ruby18", + "framework": "sinatra", + }}) + + r.Register("foo", fooEndpoint) + r.Register("foo", fooEndpoint2) }) - It("emits counter metrics", func() { + It("emits counter metrics for unregister endpoint only", func() { r.Unregister("foo", fooEndpoint) Expect(reporter.CaptureUnregistryMessageCallCount()).To(Equal(1)) - Expect(reporter.CaptureUnregistryMessageArgsForCall(0)).To(Equal(fooEndpoint)) + endpoint1, action1 := reporter.CaptureUnregistryMessageArgsForCall(0) + Expect(endpoint1).To(Equal(fooEndpoint)) + Expect(action1).To(Equal("endpoint-unregistered")) }) }) - - Context("when endpoint does not have component tag", func() { + Context("when route is not registered", func() { BeforeEach(func() { fooEndpoint.Tags = map[string]string{} }) - It("emits counter metrics", func() { + It("does not emit counter metrics for unregister", func() { r.Unregister("foo", fooEndpoint) - Expect(reporter.CaptureUnregistryMessageCallCount()).To(Equal(1)) - Expect(reporter.CaptureUnregistryMessageArgsForCall(0)).To(Equal(fooEndpoint)) + Expect(reporter.CaptureUnregistryMessageCallCount()).To(Equal(0)) }) })