From cf514baaf29da569963f91dac2683283ec255df9 Mon Sep 17 00:00:00 2001
From: Graham Christensen <graham@grahamc.com>
Date: Tue, 21 Dec 2021 19:46:19 -0500
Subject: [PATCH] hydra-notify: track the duration of handling an event

Currently we only track how long individual plugins take.
With #1083 we stop executing a lot of plugins, but we
don't have a way to measure its practical impact on the
execution time of handling events.
---
 src/script/hydra-notify | 11 ++++++++++-
 1 file changed, 10 insertions(+), 1 deletion(-)

diff --git a/src/script/hydra-notify b/src/script/hydra-notify
index c682d03d..f0ad7e6b 100755
--- a/src/script/hydra-notify
+++ b/src/script/hydra-notify
@@ -4,6 +4,7 @@ use strict;
 use warnings;
 use utf8;
 use Getopt::Long;
+use Time::HiRes qw( gettimeofday tv_interval );
 use HTTP::Server::PSGI;
 use Hydra::Event;
 use Hydra::Event::BuildFinished;
@@ -46,6 +47,11 @@ $prom->declare(
     type => "counter",
     help => "Number of events received that were unprocessable by channel."
 );
+$prom->declare(
+    "notify_event_runtime",
+    type => "histogram",
+    help => "Number of seconds spent executing events by channel."
+);
 
 my $promCfg = Hydra::Helper::Nix::getHydraNotifyPrometheusConfig($config);
 if (defined($promCfg)) {
@@ -109,6 +115,7 @@ while (!$queued_only) {
     $prom->inc("event_loop_iterations");
     my $messages = $listener->block_for_messages($taskretries->get_seconds_to_next_retry());
     while (my $message = $messages->()) {
+        my $start_time = [gettimeofday()];
         $prom->set("event_received", time());
         my $channelName = $message->{"channel"};
         my $pid = $message->{"pid"};
@@ -129,7 +136,9 @@ while (!$queued_only) {
         } or do {
             $prom->inc("notify_event_error", { channel => $channelName });
             print STDERR "error processing message '$payload' on channel '$channelName': $@\n";
-        }
+        };
+
+        $prom->histogram_observe("notify_event_runtime", tv_interval($start_time), { channel => $channelName });
     }
 
     my $task = $taskretries->get_retryable_task();