Merge branch '13411-geo-log-cursor-can-take-up-to-60-secs-to-exit' into 'master'

Resolve "Geo: Log cursor can take up to 60 secs to exit"

Closes #13411

See merge request gitlab-org/gitlab-ee!15070

ee/bin/geo_log_cursor

@@ -19,6 +19,7 @@ class GeoLogCursorOptionParser
     op.separator 'Usage: ./geo_log_cursor [options]'
     op.separator ''
     op.on('-d', '--debug', 'Enable detailed logging with extra debug information') { options[:debug] = true }
+    op.on('--stdout-logging', 'Log output to stdout') { options[:stdout_logging] = true }
 
     op.separator 'Common options:'
     op.on('-h', '--help') do
@@ -40,11 +41,24 @@ class GeoLogCursorOptionParser
   end
 end
 
+module StdoutLogger
+  def full_log_path
+    STDOUT
+  end
+end
+
 if $0 == __FILE__
   options = GeoLogCursorOptionParser.parse(ARGV)
 
   # We load rails environment / initializers only here to get faster command line startup when `--help` and `--version`
   require rails_path('config/environment.rb')
 
+  if options[:stdout_logging]
+    # Monkey patch the logging class because multiple places use it (that
+    # contain mostly class methods) and is not possible to pass
+    # options[:stdout_logging] around without a refactor.
+    Gitlab::Geo::Logger.extend(StdoutLogger)
+  end
+
   Gitlab::Geo::LogCursor::Daemon.new(options).run!
 end

ee/changelogs/unreleased/13413-geo-allow-the-log-cursor-to-log-to-stdout.yml

+---
+title: "Geo: Don't wait when exiting the log cursor"
+merge_request: 15070
+author:
+type: performance

ee/lib/gitlab/geo/log_cursor/daemon.rb

@@ -16,12 +16,14 @@ module Gitlab
         end
 
         def run!
+          logger.debug('#run!: start')
           trap_signals
 
           until exit?
             # Prevent the node from processing events unless it's a secondary
             unless Geo.secondary?
-              sleep(SECONDARY_CHECK_INTERVAL)
+              logger.debug("#run!: not a secondary, sleeping for #{SECONDARY_CHECK_INTERVAL} secs")
+              sleep_break(SECONDARY_CHECK_INTERVAL)
               next
             end
 
@@ -31,6 +33,8 @@ module Gitlab
             # When no new event is found sleep for a few moments
             arbitrary_sleep(lease[:ttl])
           end
+
+          logger.debug('#run!: finish')
         end
 
         def run_once!
@@ -45,8 +49,16 @@ module Gitlab
 
         private
 
+        def sleep_break(seconds)
+          while seconds > 0
+            sleep(1)
+            seconds -= 1
+            break if exit?
+          end
+        end
+
         def handle_events(batch, previous_batch_last_id)
-          logger.info("Handling events", first_id: batch.first.id, last_id: batch.last.id)
+          logger.info("#handle_events:", first_id: batch.first.id, last_id: batch.last.id)
 
           gap_tracking.previous_id = previous_batch_last_id
 
@@ -63,7 +75,7 @@ module Gitlab
           # If a project is deleted, the event log and its associated event data
           # could be purged from the log. We ignore this and move along.
           unless event
-            logger.warn("Unknown event", event_log_id: event_log.id)
+            logger.warn("#handle_single_event: unknown event", event_log_id: event_log.id)
             return
           end
 
@@ -89,13 +101,13 @@ module Gitlab
         end
 
         def trap_signals
-          trap(:TERM) { quit! }
-          trap(:INT) { quit! }
+          trap(:TERM) { quit!(:term) }
+          trap(:INT) { quit!(:int) }
         end
 
         # Safe shutdown
-        def quit!
-          $stdout.puts 'Exiting...'
+        def quit!(signal)
+          warn("Signal #{signal} received, Exiting...")
 
           @exit = true
         end
@@ -132,7 +144,11 @@ module Gitlab
         end
 
         def log_level
-          options[:debug] ? :debug : Rails.logger.level # rubocop:disable Gitlab/RailsLogger
+          debug_logging? ? :debug : Rails.logger.level # rubocop:disable Gitlab/RailsLogger
+        end
+
+        def debug_logging?
+          options[:debug]
         end
 
         def event_data(event_log)

ee/spec/lib/gitlab/geo/log_cursor/daemon_spec.rb

@@ -54,7 +54,7 @@ describe Gitlab::Geo::LogCursor::Daemon, :clean_gitlab_redis_shared_state do
       stub_current_geo_node(nil)
 
       is_expected.to receive(:exit?).and_return(false, true)
-      is_expected.to receive(:sleep).with(1.minute)
+      is_expected.to receive(:sleep_break).with(1.minute)
       is_expected.not_to receive(:run_once!)
 
       daemon.run!
@@ -64,7 +64,7 @@ describe Gitlab::Geo::LogCursor::Daemon, :clean_gitlab_redis_shared_state do
       stub_current_geo_node(primary)
 
       is_expected.to receive(:exit?).and_return(false, true)
-      is_expected.to receive(:sleep).with(1.minute)
+      is_expected.to receive(:sleep_break).with(1.minute)
       is_expected.not_to receive(:run_once!)
 
       daemon.run!
@@ -163,7 +163,7 @@ describe Gitlab::Geo::LogCursor::Daemon, :clean_gitlab_redis_shared_state do
         expect(Gitlab::Geo::Logger).to receive(:warn)
                                         .with(hash_including(
                                                 class: 'Gitlab::Geo::LogCursor::Daemon',
-                                                message: 'Unknown event',
+                                                message: '#handle_single_event: unknown event',
                                                 event_log_id: new_event.id))
 
         daemon.run_once!