Merge pull request #88 from Evolix/output-errors-summary

Output error summary for rake task

Gemfile

@@ -48,6 +48,8 @@ gem 'octicons'
 gem 'kaminari'
 gem 'has_scope'
 
+gem 'logging'
+
 # Reduces boot times through caching; required in config/boot.rb
 gem 'bootsnap', '>= 1.1.0', require: false
 

Gemfile.lock

@@ -166,6 +166,10 @@ GEM
       rb-fsevent (~> 0.9, >= 0.9.4)
       rb-inotify (~> 0.9, >= 0.9.7)
       ruby_dep (~> 1.2)
+    little-plugger (1.1.4)
+    logging (2.2.2)
+      little-plugger (~> 1.1)
+      multi_json (~> 1.10)
     loofah (2.2.2)
       crass (~> 1.0.2)
       nokogiri (>= 1.5.9)
@@ -363,6 +367,7 @@ DEPENDENCIES
   launchy
   letter_opener_web
   listen (>= 3.0.5, < 3.2)
+  logging
   mysql2 (>= 0.4.4, < 0.6.0)
   naught
   octicons

app/services/check_domain_processor.rb

@@ -6,10 +6,6 @@ class CheckDomainProcessor
 
   protected
 
-  def configuration_key
-    "checks_domain"
-  end
-
   def resolvers
     %i[
       resolve_last_run_failed

app/services/check_processor.rb

@@ -2,20 +2,54 @@
 # License: GNU AGPL-3+ (see full text in LICENSE file)
 
 module CheckProcessor
-  attr_reader :configuration
+  attr_reader :configuration, :logger
 
-  def initialize(configuration = nil)
-    @configuration = configuration || default_configuration
+  def initialize(configuration:, logger: NullLogger.new)
+    # Levels: debug info warn error fatal
+    @logger = logger
+    @configuration = configuration
   end
 
-  def sync_dates
-    resolvers.each do |resolver|
-      public_send(resolver).find_each(batch_size: 100).each do |check|
-        process(check)
+  def sync_dates # rubocop:disable Metrics/AbcSize,Metrics/MethodLength
+    sync_started_at = Time.now
+    logger.info "#{self.class.name}: sync_dates has started"
 
-        sleep configuration.interval
+    resolvers.each do |resolver|
+      logger.info "#{self.class.name}: using resolver '#{resolver}'"
+
+      public_send(resolver).find_in_batches(batch_size: 100) do |checks|
+        group_started_at = Time.now
+
+        checks.each do |check|
+          logger.info "#{self.class.name}: processing check ##{check.id}"
+          process(check)
+
+          logger.debug "#{self.class.name}: sleeping #{configuration.interval} seconds"
+          sleep configuration.interval
+        end
+
+        group_finished_at = Time.now
+
+        check_errors_scope(check_ids: checks.map(&:id),
+                           after_date: group_started_at,
+                           before_date: group_finished_at).includes(:check).each do |check_log|
+          message = "#{self.class.name}: check ##{check_log.check_id} for '#{check_log.check.domain}' failed (#{check_log.exit_status}) ; #{check_log.error.lines.first}" # rubocop:disable Metrics/LineLength
+          logger.error(message)
+        end
       end
     end
+
+    sync_finished_at = Time.now
+    duration = (sync_finished_at - sync_started_at).to_i
+    logger.info "#{self.class.name}: sync_dates has finished (#{duration}s)"
+  end
+
+  def check_errors_scope(check_ids:, before_date: nil, after_date: nil)
+    scope = CheckLog.failed.where("exit_status > 0").where(id: check_ids)
+    scope = scope.where("created_at <= ?", before_date) if before_date
+    scope = scope.where("created_at >= ?", after_date) if after_date
+
+    scope
   end
 
   # :nocov:
@@ -66,15 +100,5 @@ module CheckProcessor
   def process(_check)
     fail NotImplementedError, "#{self.class.name} did not implemented method #{__callee__}"
   end
-
-  def configuration_key
-    fail NotImplementedError, "#{self.class.name} did not implemented method #{__callee__}"
-  end
   # :nocov:
-
-  private
-
-  def default_configuration
-    Rails.configuration.chexpire.fetch(configuration_key)
-  end
 end

app/services/check_ssl_processor.rb

@@ -6,10 +6,6 @@ class CheckSSLProcessor
 
   protected
 
-  def configuration_key
-    "checks_ssl"
-  end
-
   def resolvers
     %i[
       resolve_all

lib/tasks/checks.rake

@@ -1,19 +1,48 @@
 # Copyright (C) 2018 Colin Darie <colin@darie.eu>, 2018 Evolix <info@evolix.fr>
 # License: GNU AGPL-3+ (see full text in LICENSE file)
 
+require "null_logger"
+
 namespace :checks do
   namespace :sync_dates do
     task all: [:domain, :ssl]
 
+    def stdout_logger(env = {}) # rubocop:disable Metrics/MethodLength
+      verbose_mode = env.fetch("VERBOSE") { 0 }.to_i == 1
+      quiet_mode   = env.fetch("QUIET")   { 0 }.to_i == 1
+      silent_mode  = env.fetch("SILENT")  { 0 }.to_i == 1
+
+      if silent_mode
+        NullLogger.new
+      else
+        logger = Logging.logger(STDOUT)
+        logger.level = if quiet_mode
+          :error
+        elsif verbose_mode
+          :debug
+        else
+          :info
+        end
+
+        logger
+      end
+    end
+
     desc "Refresh domains expiry dates"
     task domain: :environment do
-      process = CheckDomainProcessor.new
+      process = CheckDomainProcessor.new(
+        logger: stdout_logger(ENV),
+        configuration: Rails.configuration.chexpire.fetch("checks_domain"),
+      )
       process.sync_dates
     end
 
     desc "Refresh SSL expiry dates"
     task ssl: :environment do
-      process = CheckSSLProcessor.new
+      process = CheckSSLProcessor.new(
+        logger: stdout_logger(ENV),
+        configuration: Rails.configuration.chexpire.fetch("checks_ssl"),
+      )
       process.sync_dates
     end
   end

test/services/check_domain_processor_test.rb

@@ -5,7 +5,8 @@ require "test_helper"
 
 class CheckDomainProcessorTest < ActiveSupport::TestCase
   setup do
-    @processor = CheckDomainProcessor.new
+    configuration = Rails.configuration.chexpire.fetch("checks_domain")
+    @processor = CheckDomainProcessor.new(configuration: configuration)
   end
 
   test "process WhoisSyncJob for domain checks" do

test/services/check_processor_test.rb

@@ -9,10 +9,6 @@ class CheckDummyProcessor
     base_scope
   end
 
-  def configuration_key
-    "checks_dummy"
-  end
-
   def resolvers
     %i[
       resolve_expire_short_term
@@ -23,7 +19,8 @@ end
 
 class CheckProcessorTest < ActiveSupport::TestCase
   setup do
-    @processor = CheckDummyProcessor.new
+    configuration = Rails.configuration.chexpire.fetch("checks_dummy")
+    @processor = CheckDummyProcessor.new(configuration: configuration)
   end
 
   test "resolve_last_run_failed includes already and never succeeded" do
@@ -121,19 +118,15 @@ class CheckProcessorTest < ActiveSupport::TestCase
   test "#sync_dates respects the interval configuration between sends" do
     create_list(:check, 3, :expires_next_week)
 
-    configuration = Minitest::Mock.new
-    2.times do configuration.expect(:long_term_interval, 300) end
-    configuration.expect(:long_term_frequency, 4)
+    configuration = OpenStruct.new(long_term_interval: 300,
+                                   long_term_frequency: 4,
+                                   interval: 0.000001)
 
-    3.times do
-      configuration.expect(:interval, 0.000001)
-    end
-
-    processor = CheckDummyProcessor.new(configuration)
+    processor = CheckDummyProcessor.new(configuration: configuration)
 
     mock = Minitest::Mock.new
     assert_stub = lambda { |actual_time|
-      assert_equal 0.000001, actual_time
+      assert_equal configuration.interval, actual_time
       mock
     }
 
@@ -143,7 +136,6 @@ class CheckProcessorTest < ActiveSupport::TestCase
       end
     end
 
-    configuration.verify
     mock.verify
   end
 end

test/services/check_ssl_processor_test.rb

@@ -5,7 +5,8 @@ require "test_helper"
 
 class CheckSSLProcessorTest < ActiveSupport::TestCase
   setup do
-    @processor = CheckSSLProcessor.new
+    configuration = Rails.configuration.chexpire.fetch("checks_ssl")
+    @processor = CheckSSLProcessor.new(configuration: configuration)
   end
 
   test "process SSLSyncJob for ssl checks" do