From 3e7bbec40b088bfdd5d93bade9a4f84062338194 Mon Sep 17 00:00:00 2001
From: Eelco Dolstra <eelco.dolstra@logicblox.com>
Date: Fri, 10 Jul 2015 16:40:50 +0200
Subject: [PATCH] hydra-evaluator: Send statistics to statsd

---
 src/script/hydra-evaluator | 37 ++++++++++++++++++++++++++++++-------
 1 file changed, 30 insertions(+), 7 deletions(-)

diff --git a/src/script/hydra-evaluator b/src/script/hydra-evaluator
index 072a755e..e8efc75b 100755
--- a/src/script/hydra-evaluator
+++ b/src/script/hydra-evaluator
@@ -12,6 +12,8 @@ use Digest::SHA qw(sha256_hex);
 use Config::General;
 use Data::Dump qw(dump);
 use Try::Tiny;
+use Net::Statsd;
+use Time::HiRes qw(clock_gettime CLOCK_REALTIME);
 
 STDOUT->autoflush();
 STDERR->autoflush(1);
@@ -102,11 +104,17 @@ sub checkJobsetWrapped {
     my $exprType = $jobset->nixexprpath =~ /.scm$/ ? "guile" : "nix";
 
     # Fetch all values for all inputs.
-    my $checkoutStart = time;
+    my $checkoutStart = clock_gettime(CLOCK_REALTIME);
     eval {
         fetchInputs($project, $jobset, $inputInfo);
     };
+
+    Net::Statsd::increment("hydra.evaluator.checkouts");
+    my $checkoutStop = clock_gettime(CLOCK_REALTIME);
+    Net::Statsd::timing("hydra.evaluator.checkout_time", int(($checkoutStop - $checkoutStart) * 1000));
+
     if ($@) {
+        Net::Statsd::increment("hydra.evaluator.failed_checkouts");
         my $msg = $@;
         print STDERR $msg;
         txn_do($db, sub {
@@ -114,7 +122,6 @@ sub checkJobsetWrapped {
         });
         return;
     }
-    my $checkoutStop = time;
 
     # Hash the arguments to hydra-eval-jobs and check the
     # JobsetInputHashes to see if the previous evaluation had the same
@@ -124,6 +131,7 @@ sub checkJobsetWrapped {
     my $prevEval = getPrevJobsetEval($db, $jobset, 0);
     if (defined $prevEval && $prevEval->hash eq $argsHash && !$dryRun) {
         print STDERR "  jobset is unchanged, skipping\n";
+        Net::Statsd::increment("hydra.evaluator.unchanged_checkouts");
         txn_do($db, sub {
             $jobset->update({ lastcheckedtime => time, fetcherrormsg => undef });
         });
@@ -131,9 +139,11 @@ sub checkJobsetWrapped {
     }
 
     # Evaluate the job expression.
-    my $evalStart = time;
+    my $evalStart = clock_gettime(CLOCK_REALTIME);
     my ($jobs, $nixExprInput) = evalJobs($inputInfo, $exprType, $jobset->nixexprinput, $jobset->nixexprpath);
-    my $evalStop = time;
+    my $evalStop = clock_gettime(CLOCK_REALTIME);
+
+    Net::Statsd::timing("hydra.evaluator.eval_time", int(($evalStop - $evalStart) * 1000));
 
     if ($dryRun) {
         foreach my $name (keys %{$jobs}) {
@@ -150,6 +160,8 @@ sub checkJobsetWrapped {
     $jobs->{$_}->{jobName} = $_ for keys %{$jobs};
 
     my $jobOutPathMap = {};
+    my $jobsetChanged = 0;
+    my $dbStart = clock_gettime(CLOCK_REALTIME);
 
     txn_do($db, sub {
 
@@ -169,15 +181,15 @@ sub checkJobsetWrapped {
         }
 
         # Have any builds been added or removed since last time?
-        my $jobsetChanged =
+        $jobsetChanged =
             (scalar(grep { $_->{new} } values(%buildMap)) > 0)
             || (defined $prevEval && $prevEval->jobsetevalmembers->count != scalar(keys %buildMap));
 
         my $ev = $jobset->jobsetevals->create(
             { hash => $argsHash
             , timestamp => time
-            , checkouttime => abs($checkoutStop - $checkoutStart)
-            , evaltime => abs($evalStop - $evalStart)
+            , checkouttime => abs(int($checkoutStop - $checkoutStart))
+            , evaltime => abs(int($evalStop - $evalStart))
             , hasnewbuilds => $jobsetChanged ? 1 : 0
             , nrbuilds => $jobsetChanged ? scalar(keys %buildMap) : undef
             });
@@ -245,6 +257,12 @@ sub checkJobsetWrapped {
         $jobset->update({ lastcheckedtime => time });
     });
 
+    my $dbStop = clock_gettime(CLOCK_REALTIME);
+
+    Net::Statsd::timing("hydra.evaluator.db_time", int(($dbStop - $dbStart) * 1000));
+    Net::Statsd::increment("hydra.evaluator.evals");
+    Net::Statsd::increment("hydra.evaluator.cached_evals") unless $jobsetChanged;
+
     # Store the error messages for jobs that failed to evaluate.
     my $msg = "";
     foreach my $job (values %{$jobs}) {
@@ -267,10 +285,15 @@ sub checkJobset {
 
     my $triggerTime = $jobset->triggertime;
 
+    my $startTime = clock_gettime(CLOCK_REALTIME);
+
     eval {
         checkJobsetWrapped($jobset);
     };
 
+    my $stopTime = clock_gettime(CLOCK_REALTIME);
+    Net::Statsd::timing("hydra.evaluator.total_time", int(($stopTime - $startTime) * 1000));
+
     my $failed = 0;
     if ($@) {
         my $msg = $@;