Migrate rack attack logging to rack attack subscriber

Issue https://gitlab.com/gitlab-com/gl-infra/scalability/-/issues/751

config/initializers/rack_attack_logging.rb

-# frozen_string_literal: true
-#
-# Adds logging for all Rack Attack blocks and throttling events.
-
-ActiveSupport::Notifications.subscribe(/rack_attack/) do |name, start, finish, request_id, payload|
-  req = payload[:request]
-
-  case req.env['rack.attack.match_type']
-  when :throttle, :blocklist, :track
-    rack_attack_info = {
-      message: 'Rack_Attack',
-      env: req.env['rack.attack.match_type'],
-      remote_ip: req.ip,
-      request_method: req.request_method,
-      path: req.fullpath,
-      matched: req.env['rack.attack.matched']
-    }
-
-    throttles_with_user_information = [
-      :throttle_authenticated_api,
-      :throttle_authenticated_web,
-      :throttle_authenticated_protected_paths_api,
-      :throttle_authenticated_protected_paths_web
-    ]
-
-    if throttles_with_user_information.include? req.env['rack.attack.matched'].to_sym
-      user_id = req.env['rack.attack.match_discriminator']
-      user = User.find_by(id: user_id)
-
-      rack_attack_info[:user_id] = user_id
-      rack_attack_info['meta.user'] = user.username unless user.nil?
-    end
-
-    Gitlab::AuthLogger.error(rack_attack_info)
-  when :safelist
-    Gitlab::Instrumentation::Throttle.safelist = req.env['rack.attack.matched']
-  end
-end

lib/gitlab/metrics/subscribers/rack_attack.rb

@@ -3,17 +3,25 @@
 module Gitlab
   module Metrics
     module Subscribers
-      # Instrument the cache operations of RackAttack to use in structured
+      # - Adds logging for all Rack Attack blocks and throttling events.
+      # - Instrument the cache operations of RackAttack to use in structured
       # logs. Two fields are exposed:
-      # - rack_attack_redis_count: the number of redis calls triggered by
-      # RackAttack in a request.
-      # - rack_attack_redis_duration_s: the total duration of all redis calls
-      # triggered by RackAttack in a request.
+      #   + rack_attack_redis_count: the number of redis calls triggered by
+      #   RackAttack in a request.
+      #   + rack_attack_redis_duration_s: the total duration of all redis calls
+      #   triggered by RackAttack in a request.
       class RackAttack < ActiveSupport::Subscriber
         attach_to 'rack_attack'
 
         INSTRUMENTATION_STORE_KEY = :rack_attack_instrumentation
 
+        THROTTLES_WITH_USER_INFORMATION = [
+          :throttle_authenticated_api,
+          :throttle_authenticated_web,
+          :throttle_authenticated_protected_paths_api,
+          :throttle_authenticated_protected_paths_web
+        ].freeze
+
         PAYLOAD_KEYS = [
           :rack_attack_redis_count,
           :rack_attack_redis_duration_s
@@ -26,10 +34,55 @@ module Gitlab
           }
         end
 
+        def initialize(auth_logger: Gitlab::AuthLogger)
+          @auth_logger = auth_logger
+        end
+
         def redis(event)
           self.class.payload[:rack_attack_redis_count] += 1
           self.class.payload[:rack_attack_redis_duration_s] += event.duration.to_f / 1000
         end
+
+        def safelist(event)
+          req = event.payload[:request]
+          Gitlab::Instrumentation::Throttle.safelist = req.env['rack.attack.matched']
+        end
+
+        def throttle(event)
+          log_into_auth_logger(event)
+        end
+
+        def blocklist(event)
+          log_into_auth_logger(event)
+        end
+
+        def track(event)
+          log_into_auth_logger(event)
+        end
+
+        private
+
+        def log_into_auth_logger(event)
+          req = event.payload[:request]
+          rack_attack_info = {
+            message: 'Rack_Attack',
+            env: req.env['rack.attack.match_type'],
+            remote_ip: req.ip,
+            request_method: req.request_method,
+            path: req.fullpath,
+            matched: req.env['rack.attack.matched']
+          }
+
+          if THROTTLES_WITH_USER_INFORMATION.include? req.env['rack.attack.matched'].to_sym
+            user_id = req.env['rack.attack.match_discriminator']
+            user = User.find_by(id: user_id) # rubocop:disable CodeReuse/ActiveRecord
+
+            rack_attack_info[:user_id] = user_id
+            rack_attack_info['meta.user'] = user.username unless user.nil?
+          end
+
+          @auth_logger.error(rack_attack_info)
+        end
       end
     end
   end

spec/lib/gitlab/metrics/subscribers/rack_attack_spec.rb

@@ -3,7 +3,8 @@
 require 'spec_helper'
 
 RSpec.describe Gitlab::Metrics::Subscribers::RackAttack, :request_store do
-  let(:subscriber) { described_class.new }
+  let(:logger) { double(:logger) }
+  let(:subscriber) { described_class.new(auth_logger: logger) }
 
   describe '.payload' do
     context 'when the request store is empty' do
@@ -58,4 +59,140 @@ RSpec.describe Gitlab::Metrics::Subscribers::RackAttack, :request_store do
       )
     end
   end
+
+  shared_examples 'log into auth logger' do
+    context 'when matched throttle does not require user information' do
+      let(:event) do
+        ActiveSupport::Notifications::Event.new(
+          event_name, Time.current, Time.current + 2.seconds, '1', request: double(
+            :request,
+            ip: '1.2.3.4',
+            request_method: 'GET',
+            fullpath: '/api/v4/internal/authorized_keys',
+            env: {
+              'rack.attack.match_type' => match_type,
+              'rack.attack.matched' => 'throttle_unauthenticated'
+            }
+          )
+        )
+      end
+
+      it 'logs request information' do
+        expect(logger).to receive(:error).with(
+          message: 'Rack_Attack',
+          env: match_type,
+          remote_ip: '1.2.3.4',
+          request_method: 'GET',
+          path: '/api/v4/internal/authorized_keys',
+          matched: 'throttle_unauthenticated'
+        )
+        subscriber.send(match_type, event)
+      end
+    end
+
+    context 'when matched throttle requires user information' do
+      context 'when user not found' do
+        let(:event) do
+          ActiveSupport::Notifications::Event.new(
+            event_name, Time.current, Time.current + 2.seconds, '1', request: double(
+              :request,
+              ip: '1.2.3.4',
+              request_method: 'GET',
+              fullpath: '/api/v4/internal/authorized_keys',
+              env: {
+                'rack.attack.match_type' => match_type,
+                'rack.attack.matched' => 'throttle_authenticated_api',
+                'rack.attack.match_discriminator' => 'not_exist_user_id'
+              }
+            )
+          )
+        end
+
+        it 'logs request information and user id' do
+          expect(logger).to receive(:error).with(
+            message: 'Rack_Attack',
+            env: match_type,
+            remote_ip: '1.2.3.4',
+            request_method: 'GET',
+            path: '/api/v4/internal/authorized_keys',
+            matched: 'throttle_authenticated_api',
+            user_id: 'not_exist_user_id'
+          )
+          subscriber.send(match_type, event)
+        end
+      end
+
+      context 'when user found' do
+        let(:user) { create(:user) }
+        let(:event) do
+          ActiveSupport::Notifications::Event.new(
+            event_name, Time.current, Time.current + 2.seconds, '1', request: double(
+              :request,
+              ip: '1.2.3.4',
+              request_method: 'GET',
+              fullpath: '/api/v4/internal/authorized_keys',
+              env: {
+                'rack.attack.match_type' => match_type,
+                'rack.attack.matched' => 'throttle_authenticated_api',
+                'rack.attack.match_discriminator' => user.id
+              }
+            )
+          )
+        end
+
+        it 'logs request information and user meta' do
+          expect(logger).to receive(:error).with(
+            message: 'Rack_Attack',
+            env: match_type,
+            remote_ip: '1.2.3.4',
+            request_method: 'GET',
+            path: '/api/v4/internal/authorized_keys',
+            matched: 'throttle_authenticated_api',
+            user_id: user.id,
+            'meta.user' => user.username
+          )
+          subscriber.send(match_type, event)
+        end
+      end
+    end
+  end
+
+  describe '#throttle' do
+    let(:match_type) { :throttle }
+    let(:event_name) { 'throttle.rack_attack' }
+
+    it_behaves_like 'log into auth logger'
+  end
+
+  describe '#blocklist' do
+    let(:match_type) { :blocklist }
+    let(:event_name) { 'blocklist.rack_attack' }
+
+    it_behaves_like 'log into auth logger'
+  end
+
+  describe '#track' do
+    let(:match_type) { :track }
+    let(:event_name) { 'track.rack_attack' }
+
+    it_behaves_like 'log into auth logger'
+  end
+
+  describe '#safelist' do
+    let(:event) do
+      ActiveSupport::Notifications::Event.new(
+        'safelist.rack_attack', Time.current, Time.current + 2.seconds, '1', request: double(
+          :request,
+          env: {
+            'rack.attack.matched' => 'throttle_unauthenticated'
+          }
+        )
+      )
+    end
+
+    it 'adds the matched name to safe request store' do
+      subscriber.safelist(event)
+      expect(Gitlab::SafeRequestStore[:instrumentation_throttle_safelist]).to eql('throttle_unauthenticated')
+    end
+  end
 end