From 954c8086df0a2884001e2c64a4eaae98c0a8fc0a Mon Sep 17 00:00:00 2001
From: Jorn van de Beek <jorn@roqua.nl>
Date: Tue, 11 Jun 2019 14:29:03 +0000
Subject: [PATCH] Measure cron calls

---
 Gemfile                                     |  1 +
 Gemfile.lock                                |  3 ++-
 lib/roqua/probes/base_probe.rb              | 20 ++++++++++++++++----
 lib/roqua/probes/delayed_job_probe.rb       |  4 ++--
 lib/roqua/probes/monitoring_probe.rb        |  4 ++--
 lib/roqua/probes/scheduling_probe.rb        |  4 ++--
 lib/roqua/scheduling/scheduler.rb           |  1 +
 spec/roqua/probes/delayed_job_probe_spec.rb |  9 +++++++--
 spec/roqua/probes/monitoring_probe_spec.rb  | 11 ++++++++---
 spec/roqua/scheduling/scheduler_spec.rb     |  9 ++++++++-
 10 files changed, 49 insertions(+), 17 deletions(-)

diff --git a/Gemfile b/Gemfile
index ad25f50..337fa4a 100644
--- a/Gemfile
+++ b/Gemfile
@@ -17,4 +17,5 @@ group :test do
   gem 'responders'
   gem 'rspec-instrumentation-matcher'
   gem 'rspec-rails'
+  gem 'pry'
 end
diff --git a/Gemfile.lock b/Gemfile.lock
index 1f7b53e..f875a33 100644
--- a/Gemfile.lock
+++ b/Gemfile.lock
@@ -188,6 +188,7 @@ DEPENDENCIES
   delayed_job_active_record
   fakefs
   guard-rspec (~> 4.2.6)
+  pry
   rake
   responders
   roqua-support!
@@ -199,4 +200,4 @@ DEPENDENCIES
   timecop
 
 BUNDLED WITH
-   1.16.6
+   1.17.3
diff --git a/lib/roqua/probes/base_probe.rb b/lib/roqua/probes/base_probe.rb
index 61411e5..84a781a 100644
--- a/lib/roqua/probes/base_probe.rb
+++ b/lib/roqua/probes/base_probe.rb
@@ -1,12 +1,24 @@
+require 'active_support/concern'
+
 module Roqua
   module Probes
     module BaseProbe
-      def enable
-        new.tap do |probe|
-          probe_sym = probe.class.to_s.to_sym
-          Appsignal::Minutely.probes.register(probe_sym, probe) unless Appsignal::Minutely.probes[probe_sym]
+      extend ActiveSupport::Concern
+
+      class_methods do
+        def enable
+          new.tap do |probe|
+            probe_sym = probe.class.to_s.to_sym
+            Appsignal::Minutely.probes.register(probe_sym, probe) unless Appsignal::Minutely.probes[probe_sym]
+          end
         end
       end
+
+      # do not override me, implement probes by implementing the #run method
+      def call
+        run
+        Appsignal.increment_counter("probe.call.completed.#{self.class.name.demodulize.underscore}", 1)
+      end
     end
   end
 end
diff --git a/lib/roqua/probes/delayed_job_probe.rb b/lib/roqua/probes/delayed_job_probe.rb
index ae3e62e..be31945 100644
--- a/lib/roqua/probes/delayed_job_probe.rb
+++ b/lib/roqua/probes/delayed_job_probe.rb
@@ -3,13 +3,13 @@ require_relative 'base_probe'
 module Roqua
   module Probes
     class DelayedJobProbe
-      extend BaseProbe
+      include BaseProbe
 
       def backlog_count
         Delayed::Job.where(locked_at: nil).where('run_at < ?', Time.zone.now).count
       end
 
-      def call
+      def run
         Appsignal.set_gauge('delayed_job_backlog_count', backlog_count)
       end
     end
diff --git a/lib/roqua/probes/monitoring_probe.rb b/lib/roqua/probes/monitoring_probe.rb
index 77db5a0..94aa449 100644
--- a/lib/roqua/probes/monitoring_probe.rb
+++ b/lib/roqua/probes/monitoring_probe.rb
@@ -3,7 +3,7 @@ require_relative 'base_probe'
 module Roqua
   module Probes
     class MonitoringProbe
-      extend BaseProbe
+      include BaseProbe
 
       def incomplete_jobs
         Roqua::Scheduling::CronJob.where('completed_at IS NULL OR completed_at < next_run_at')
@@ -19,7 +19,7 @@ module Roqua
         (longest_delay_in_seconds / 1.minute).to_i
       end
 
-      def call
+      def run
         Appsignal.set_gauge('scheduler_delay_in_minutes', longest_delay_in_minutes)
       end
     end
diff --git a/lib/roqua/probes/scheduling_probe.rb b/lib/roqua/probes/scheduling_probe.rb
index c5a17ab..d794036 100644
--- a/lib/roqua/probes/scheduling_probe.rb
+++ b/lib/roqua/probes/scheduling_probe.rb
@@ -3,9 +3,9 @@ require_relative 'base_probe'
 module Roqua
   module Probes
     class SchedulingProbe
-      extend BaseProbe
+      include BaseProbe
 
-      def call
+      def run
         ActiveRecord::Base.establish_connection
         require_relative Rails.root.join('config', 'schedule.rb')
         Roqua::Scheduling::Scheduler.new.ping
diff --git a/lib/roqua/scheduling/scheduler.rb b/lib/roqua/scheduling/scheduler.rb
index 5ef3e38..5a9ec1d 100644
--- a/lib/roqua/scheduling/scheduler.rb
+++ b/lib/roqua/scheduling/scheduler.rb
@@ -42,6 +42,7 @@ class Roqua::Scheduling::Scheduler
     task = schedule.tasks[cron_job.name]
     task.run
 
+    Appsignal.increment_counter("scheduler.run_task.completed.#{task.name}", 1)
     cron_job.update completed_at: Time.now, next_run_at: task.next_run_at
   end
 end
diff --git a/spec/roqua/probes/delayed_job_probe_spec.rb b/spec/roqua/probes/delayed_job_probe_spec.rb
index 39c1151..f4724b0 100644
--- a/spec/roqua/probes/delayed_job_probe_spec.rb
+++ b/spec/roqua/probes/delayed_job_probe_spec.rb
@@ -7,7 +7,7 @@ require 'roqua/probes/delayed_job_probe'
 describe Roqua::Probes::DelayedJobProbe do
   before { Timecop.freeze }
   after { Timecop.return }
-  subject(:probe) { Roqua::Probes::DelayedJobProbe.new }
+  subject(:probe) { described_class.new }
 
   describe 'backlog_count' do
     context 'if a single job unlocked job exists that has a run_at in the past' do
@@ -24,12 +24,17 @@ describe Roqua::Probes::DelayedJobProbe do
     end
   end
 
-  describe 'call' do
+  describe '#call' do
     it 'sends the correct metric to Appsignal' do
       expect(probe).to receive(:backlog_count).and_return(12)
       expect(Appsignal).to receive(:set_gauge).with('delayed_job_backlog_count', 12)
       probe.call
     end
+
+    it 'increments the probe call counter' do
+      expect(Appsignal).to receive(:increment_counter).with('probe.call.completed.delayed_job_probe', 1)
+      probe.call
+    end
   end
 
   context '.enable' do
diff --git a/spec/roqua/probes/monitoring_probe_spec.rb b/spec/roqua/probes/monitoring_probe_spec.rb
index 09a5663..fafa32f 100644
--- a/spec/roqua/probes/monitoring_probe_spec.rb
+++ b/spec/roqua/probes/monitoring_probe_spec.rb
@@ -4,21 +4,26 @@ require 'timecop'
 
 require 'roqua/probes/delayed_job_probe'
 
-describe Roqua::Probes::DelayedJobProbe do
+describe Roqua::Probes::MonitoringProbe do
   before { Timecop.freeze }
   after { Timecop.return }
-  subject(:probe) { Roqua::Probes::MonitoringProbe.new }
+  subject(:probe) { described_class.new }
 
   before do
     Roqua::Scheduling::CronJob.delete_all
   end
 
-  describe 'call' do
+  describe '#call' do
     it 'sends data to AppSignal' do
       expect(Appsignal).to receive(:set_gauge).with('scheduler_delay_in_minutes', 10)
       expect(probe).to receive(:longest_delay_in_minutes).and_return(10)
       probe.call
     end
+
+    it 'increments the probe call counter' do
+      expect(Appsignal).to receive(:increment_counter).with('probe.call.completed.monitoring_probe', 1)
+      probe.call
+    end
   end
 
   describe 'longest_delay' do
diff --git a/spec/roqua/scheduling/scheduler_spec.rb b/spec/roqua/scheduling/scheduler_spec.rb
index 59ced22..843a4c5 100644
--- a/spec/roqua/scheduling/scheduler_spec.rb
+++ b/spec/roqua/scheduling/scheduler_spec.rb
@@ -72,16 +72,23 @@ describe Roqua::Scheduling::Scheduler do
   describe 'callbacks' do
     let(:callback_spy) { spy(:callback) }
 
-    it 'get executed' do
+    before do
       Roqua::Scheduling::Schedule.setup do |cron|
         cron.add_task 'hourly', next_run_at: proc { 1.minute.ago } do
           callback_spy.execute
         end
       end
+    end
 
+    it 'get executed' do
       expect(callback_spy).to receive(:execute)
       subject.ping
     end
+
+    it 'counts task calls' do
+      expect(Appsignal).to receive(:increment_counter).with('scheduler.run_task.completed.hourly', 1)
+      subject.ping
+    end
   end
 
   describe 'when running multiple times' do
-- 
GitLab