From d74f61855f0b8056ef393a8fb80e9dd60993bb83 Mon Sep 17 00:00:00 2001 From: Jakub Hrozek Date: Mon, 30 Oct 2023 21:35:35 +0100 Subject: [PATCH] Add watermill event histogram (#1329) We're able to get a histogram of how long does it take for the individual watermill events to execute: ``` elapsed while executing the handler function in seconds mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.0005"} 0 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.001"} 0 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.0025"} 0 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.005"} 0 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.01"} 0 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.025"} 0 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.05"} 0 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.1"} 2 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.25"} 2 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="0.5"} 2 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="1"} 2 mediator_eventer_handler_execution_time_seconds_bucket{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true",le="+Inf"} 2 mediator_eventer_handler_execution_time_seconds_sum{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true"} 0.125726416 mediator_eventer_handler_execution_time_seconds_count{handler_name="github.com/stacklok/mediator/internal/engine.(*Executor).HandleEntityEvent-fm-internal.entity.event",success="true"} 2 ``` --- go.mod | 1 + go.sum | 2 ++ internal/events/eventer.go | 27 +++++++++++++++++++++++++-- 3 files changed, 28 insertions(+), 2 deletions(-) diff --git a/go.mod b/go.mod index 933588f3c5..f0c3f0e9e0 100644 --- a/go.mod +++ b/go.mod @@ -74,6 +74,7 @@ require ( github.com/containerd/console v1.0.4-0.20230313162750-1ae8d489ac81 // indirect github.com/decred/dcrd/dcrec/secp256k1/v4 v4.2.0 // indirect github.com/felixge/httpsnoop v1.0.3 // indirect + github.com/go-chi/chi/v5 v5.0.8 // indirect github.com/gorilla/schema v1.2.0 // indirect github.com/lestrrat-go/blackmagic v1.0.2 // indirect github.com/lestrrat-go/httpcc v1.0.1 // indirect diff --git a/go.sum b/go.sum index c510c0ac72..79ea921c56 100644 --- a/go.sum +++ b/go.sum @@ -408,6 +408,8 @@ github.com/gliderlabs/ssh v0.3.5/go.mod h1:8XB4KraRrX39qHhT6yxPsHedjA08I/uBVwj4x github.com/go-chi/chi v4.0.2+incompatible/go.mod h1:eB3wogJHnLi3x/kFX2A+IbTBlXxmMeXJVKy9tTv1XzQ= github.com/go-chi/chi v4.1.2+incompatible h1:fGFk2Gmi/YKXk0OmGfBh0WgmN3XB8lVnEyNz34tQRec= github.com/go-chi/chi v4.1.2+incompatible/go.mod h1:eB3wogJHnLi3x/kFX2A+IbTBlXxmMeXJVKy9tTv1XzQ= +github.com/go-chi/chi/v5 v5.0.8 h1:lD+NLqFcAi1ovnVZpsnObHGW4xb4J8lNmoYVfECH1Y0= +github.com/go-chi/chi/v5 v5.0.8/go.mod h1:DslCQbL2OYiznFReuXYUmQ2hGd1aDpCnlMNITLSKoi8= github.com/go-git/gcfg v1.5.1-0.20230307220236-3a3c6141e376 h1:+zs/tPmkDkHx3U66DAb0lQFJrpS6731Oaa12ikc+DiI= github.com/go-git/gcfg v1.5.1-0.20230307220236-3a3c6141e376/go.mod h1:an3vInlBmSxCcxctByoQdvwPiA7DTK7jaaFDBTtu0ic= github.com/go-git/go-billy/v5 v5.5.0 h1:yEY4yhzCDuMGSv83oGxiBotRzhwhNr8VZyphhiu+mTU= diff --git a/internal/events/eventer.go b/internal/events/eventer.go index 17df641d8f..5efcd11666 100644 --- a/internal/events/eventer.go +++ b/internal/events/eventer.go @@ -26,10 +26,12 @@ import ( "time" "github.com/ThreeDotsLabs/watermill" + "github.com/ThreeDotsLabs/watermill/components/metrics" "github.com/ThreeDotsLabs/watermill/message" "github.com/ThreeDotsLabs/watermill/message/router/middleware" "github.com/ThreeDotsLabs/watermill/pubsub/gochannel" "github.com/alexdrl/zerowater" + promgo "github.com/prometheus/client_golang/prometheus" "github.com/rs/zerolog" "github.com/stacklok/mediator/internal/config" @@ -43,6 +45,11 @@ const ( GithubWebhookEventTypeKey = "type" ) +const ( + metricsNamespace = "mediator" + metricsSubsystem = "eventer" +) + // Handler is an alias for the watermill handler type, which is both wordy and may be // detail we don't want to expose. type Handler = message.NoPublishHandlerFunc @@ -100,6 +107,12 @@ func Setup(ctx context.Context, cfg *config.EventConfig) (*Eventer, error) { return nil, err } + metricsBuilder := metrics.NewPrometheusMetricsBuilder( + promgo.DefaultRegisterer, + metricsNamespace, + metricsSubsystem) + metricsBuilder.AddPrometheusRouterMetrics(router) + // Router level middleware are executed for every message sent to the router router.AddMiddleware( // CorrelationID will copy the correlation id from the incoming message's metadata to the produced messages @@ -123,10 +136,20 @@ func Setup(ctx context.Context, cfg *config.EventConfig) (*Eventer, error) { return nil, fmt.Errorf("failed instantiating driver: %w", err) } + pubWithMetrics, err := metricsBuilder.DecoratePublisher(pub) + if err != nil { + return nil, fmt.Errorf("failed to decorate publisher: %w", err) + } + + subWithMetrics, err := metricsBuilder.DecorateSubscriber(sub) + if err != nil { + return nil, fmt.Errorf("failed to decorate subscriber: %w", err) + } + return &Eventer{ router: router, - webhookPublisher: pub, - webhookSubscriber: sub, + webhookPublisher: pubWithMetrics, + webhookSubscriber: subWithMetrics, }, nil }