Merge branch 'feature/gb/login-activity-metrics' into 'master'

Add user authentication activity metrics

Closes #47789

See merge request gitlab-org/gitlab-ce!20668

app/controllers/application_controller.rb

@@ -397,7 +397,7 @@ class ApplicationController < ActionController::Base
       # actually stored in the session and a token is needed
       # for every request. If you want the token to work as a
       # sign in token, you can simply remove store: false.
-      sign_in user, store: false
+      sign_in(user, store: false, message: :sessionless_sign_in)
     end
   end
 

app/controllers/concerns/authenticates_with_two_factor.rb

@@ -60,7 +60,7 @@ module AuthenticatesWithTwoFactor
 
       remember_me(user) if user_params[:remember_me] == '1'
       user.save!
-      sign_in(user)
+      sign_in(user, message: :two_factor_authenticated)
     else
       user.increment_failed_attempts!
       Gitlab::AppLogger.info("Failed Login: user=#{user.username} ip=#{request.remote_ip} method=OTP")
@@ -77,7 +77,7 @@ module AuthenticatesWithTwoFactor
       session.delete(:challenge)
 
       remember_me(user) if user_params[:remember_me] == '1'
-      sign_in(user)
+      sign_in(user, message: :two_factor_authenticated)
     else
       user.increment_failed_attempts!
       Gitlab::AppLogger.info("Failed Login: user=#{user.username} ip=#{request.remote_ip} method=U2F")

app/controllers/sessions_controller.rb

@@ -89,6 +89,14 @@ class SessionsController < Devise::SessionsController
     ).increment
   end
 
+  ##
+  # We do have some duplication between lib/gitlab/auth/activity.rb here, but
+  # leaving this method here because of backwards compatibility.
+  #
+  def login_counter
+    @login_counter ||= Gitlab::Metrics.counter(:user_session_logins_total, 'User sign in count')
+  end
+
   def log_failed_login
     Gitlab::AppLogger.info("Failed Login: username=#{user_params[:login]} ip=#{request.remote_ip}")
   end
@@ -97,10 +105,6 @@ class SessionsController < Devise::SessionsController
     (options = env["warden.options"]) && options[:action] == "unauthenticated"
   end
 
-  def login_counter
-    @login_counter ||= Gitlab::Metrics.counter(:user_session_logins_total, 'User sign in count')
-  end
-
   # Handle an "initial setup" state, where there's only one user, it's an admin,
   # and they require a password change.
   def check_initial_setup

changelogs/unreleased/feature-gb-login-activity-metrics.yml

+---
+title: Add more comprehensive metrics tracking authentication activity
+merge_request: 20668
+author:
+type: added

config/initializers/warden.rb

 Rails.application.configure do |config|
   Warden::Manager.after_set_user(scope: :user) do |user, auth, opts|
     Gitlab::Auth::UniqueIpsLimiter.limit_user!(user)
-  end
 
-  Warden::Manager.before_failure(scope: :user) do |env, opts|
-    Gitlab::Auth::BlockedUserTracker.log_if_user_blocked(env)
+    activity = Gitlab::Auth::Activity.new(user, opts)
+
+    case opts[:event]
+    when :authentication
+      activity.user_authenticated!
+    when :set_user
+      activity.user_authenticated!
+      activity.user_session_override!
+    when :fetch # rubocop:disable Lint/EmptyWhen
+      # We ignore session fetch events
+    else
+      activity.user_session_override!
+    end
   end
 
   Warden::Manager.after_authentication(scope: :user) do |user, auth, opts|
@@ -15,7 +25,17 @@ Rails.application.configure do |config|
     ActiveSession.set(user, auth.request)
   end
 
-  Warden::Manager.before_logout(scope: :user) do |user, auth, opts|
-    ActiveSession.destroy(user || auth.user, auth.request.session.id)
+  Warden::Manager.before_failure(scope: :user) do |env, opts|
+    tracker = Gitlab::Auth::BlockedUserTracker.new(env)
+    tracker.log_blocked_user_activity! if tracker.user_blocked?
+
+    Gitlab::Auth::Activity.new(tracker.user, opts).user_authentication_failed!
+  end
+
+  Warden::Manager.before_logout(scope: :user) do |user_warden, auth, opts|
+    user = user_warden || auth.user
+
+    ActiveSession.destroy(user, auth.request.session.id)
+    Gitlab::Auth::Activity.new(user, opts).user_session_destroyed!
   end
 end

lib/gitlab/auth/activity.rb

+module Gitlab
+  module Auth
+    ##
+    # Metrics and logging for user authentication activity.
+    #
+    class Activity
+      extend Gitlab::Utils::StrongMemoize
+
+      COUNTERS = {
+        user_authenticated: 'Counter of successful authentication events',
+        user_unauthenticated: 'Counter of authentication failures',
+        user_not_found: 'Counter of failed log-ins when user is unknown',
+        user_password_invalid: 'Counter of failed log-ins with invalid password',
+        user_session_override: 'Counter of manual log-ins and sessions overrides',
+        user_session_destroyed: 'Counter of user sessions being destroyed',
+        user_two_factor_authenticated: 'Counter of two factor authentications',
+        user_sessionless_authentication: 'Counter of sessionless authentications',
+        user_blocked: 'Counter of sign in attempts when user is blocked'
+      }.freeze
+
+      def initialize(user, opts)
+        @user = user
+        @opts = opts
+      end
+
+      def user_authentication_failed!
+        self.class.user_unauthenticated_counter_increment!
+
+        case @opts[:message]
+        when :not_found_in_database
+          self.class.user_not_found_counter_increment!
+        when :invalid
+          self.class.user_password_invalid_counter_increment!
+        end
+
+        self.class.user_blocked_counter_increment! if @user&.blocked?
+      end
+
+      def user_authenticated!
+        self.class.user_authenticated_counter_increment!
+      end
+
+      def user_session_override!
+        self.class.user_session_override_counter_increment!
+
+        case @opts[:message]
+        when :two_factor_authenticated
+          self.class.user_two_factor_authenticated_counter_increment!
+        when :sessionless_sign_in
+          self.class.user_sessionless_authentication_counter_increment!
+        end
+      end
+
+      def user_session_destroyed!
+        self.class.user_session_destroyed_counter_increment!
+      end
+
+      def self.each_counter
+        COUNTERS.each_pair do |metric, description|
+          yield "#{metric}_counter", metric, description
+        end
+      end
+
+      each_counter do |counter, metric, description|
+        define_singleton_method(counter) do
+          strong_memoize(counter) do
+            Gitlab::Metrics.counter("gitlab_auth_#{metric}_total".to_sym, description)
+          end
+        end
+
+        define_singleton_method("#{counter}_increment!") do
+          public_send(counter).increment # rubocop:disable GitlabSecurity/PublicSend
+        end
+      end
+    end
+  end
+end

lib/gitlab/auth/blocked_user_tracker.rb

@@ -2,37 +2,58 @@
 module Gitlab
   module Auth
     class BlockedUserTracker
+      include Gitlab::Utils::StrongMemoize
+
       ACTIVE_RECORD_REQUEST_PARAMS = 'action_dispatch.request.request_parameters'
 
-      def self.log_if_user_blocked(env)
-        message = env.dig('warden.options', :message)
+      def initialize(env)
+        @env = env
+      end
 
-        # Devise calls User#active_for_authentication? on the User model and then
-        # throws an exception to Warden with User#inactive_message:
-        # https://github.com/plataformatec/devise/blob/v4.2.1/lib/devise/hooks/activatable.rb#L8
-        #
-        # Since Warden doesn't pass the user record to the failure handler, we
-        # need to do a database lookup with the username. We can limit the
-        # lookups to happen when the user was blocked by checking the inactive
-        # message passed along by Warden.
-        return unless message == User::BLOCKED_MESSAGE
+      def user_blocked?
+        user&.blocked?
+      end
 
-        # Check for either LDAP or regular GitLab account logins
-        login = env.dig(ACTIVE_RECORD_REQUEST_PARAMS, 'username') ||
-          env.dig(ACTIVE_RECORD_REQUEST_PARAMS, 'user', 'login')
+      def user
+        return unless has_user_blocked_message?
 
-        return unless login.present?
+        strong_memoize(:user) do
+          # Check for either LDAP or regular GitLab account logins
+          login = @env.dig(ACTIVE_RECORD_REQUEST_PARAMS, 'username') ||
+            @env.dig(ACTIVE_RECORD_REQUEST_PARAMS, 'user', 'login')
 
-        user = User.by_login(login)
+          User.by_login(login) if login.present?
+        end
+      rescue TypeError
+      end
 
-        return unless user&.blocked?
+      def log_blocked_user_activity!
+        return unless user_blocked?
 
-        Gitlab::AppLogger.info("Failed login for blocked user: user=#{user.username} ip=#{env['REMOTE_ADDR']}")
+        Gitlab::AppLogger.info("Failed login for blocked user: user=#{user.username} ip=#{@env['REMOTE_ADDR']}")
         SystemHooksService.new.execute_hooks_for(user, :failed_login)
-
         true
       rescue TypeError
       end
+
+      private
+
+      ##
+      # Devise calls User#active_for_authentication? on the User model and then
+      # throws an exception to Warden with User#inactive_message:
+      # https://github.com/plataformatec/devise/blob/v4.2.1/lib/devise/hooks/activatable.rb#L8
+      #
+      # Since Warden doesn't pass the user record to the failure handler, we
+      # need to do a database lookup with the username. We can limit the
+      # lookups to happen when the user was blocked by checking the inactive
+      # message passed along by Warden.
+      #
+      def has_user_blocked_message?
+        strong_memoize(:user_blocked_message) do
+          message = @env.dig('warden.options', :message)
+          message == User::BLOCKED_MESSAGE
+        end
+      end
     end
   end
 end

spec/controllers/application_controller_spec.rb

@@ -57,6 +57,10 @@ describe ApplicationController do
   end
 
   describe "#authenticate_user_from_personal_access_token!" do
+    before do
+      stub_authentication_activity_metrics(debug: false)
+    end
+
     controller(described_class) do
       def index
         render text: 'authenticated'
@@ -67,7 +71,13 @@ describe ApplicationController do
 
     context "when the 'personal_access_token' param is populated with the personal access token" do
       it "logs the user in" do
+        expect(authentication_metrics)
+          .to increment(:user_authenticated_counter)
+          .and increment(:user_session_override_counter)
+          .and increment(:user_sessionless_authentication_counter)
+
         get :index, private_token: personal_access_token.token
+
         expect(response).to have_gitlab_http_status(200)
         expect(response.body).to eq('authenticated')
       end
@@ -75,15 +85,25 @@ describe ApplicationController do
 
     context "when the 'PERSONAL_ACCESS_TOKEN' header is populated with the personal access token" do
       it "logs the user in" do
+        expect(authentication_metrics)
+          .to increment(:user_authenticated_counter)
+          .and increment(:user_session_override_counter)
+          .and increment(:user_sessionless_authentication_counter)
+
         @request.headers["PRIVATE-TOKEN"] = personal_access_token.token
         get :index
+
         expect(response).to have_gitlab_http_status(200)
         expect(response.body).to eq('authenticated')
       end
     end
 
     it "doesn't log the user in otherwise" do
+      expect(authentication_metrics)
+        .to increment(:user_unauthenticated_counter)
+
       get :index, private_token: "token"
+
       expect(response.status).not_to eq(200)
       expect(response.body).not_to eq('authenticated')
     end
@@ -174,6 +194,10 @@ describe ApplicationController do
   end
 
   describe '#authenticate_sessionless_user!' do
+    before do
+      stub_authentication_activity_metrics(debug: false)
+    end
+
     describe 'authenticating a user from a feed token' do
       controller(described_class) do
         def index
@@ -184,7 +208,13 @@ describe ApplicationController do
       context "when the 'feed_token' param is populated with the feed token" do
         context 'when the request format is atom' do
           it "logs the user in" do
+            expect(authentication_metrics)
+              .to increment(:user_authenticated_counter)
+              .and increment(:user_session_override_counter)
+              .and increment(:user_sessionless_authentication_counter)
+
             get :index, feed_token: user.feed_token, format: :atom
+
             expect(response).to have_gitlab_http_status 200
             expect(response.body).to eq 'authenticated'
           end
@@ -192,7 +222,13 @@ describe ApplicationController do
 
         context 'when the request format is ics' do
           it "logs the user in" do
+            expect(authentication_metrics)
+              .to increment(:user_authenticated_counter)
+              .and increment(:user_session_override_counter)
+              .and increment(:user_sessionless_authentication_counter)
+
             get :index, feed_token: user.feed_token, format: :ics
+
             expect(response).to have_gitlab_http_status 200
             expect(response.body).to eq 'authenticated'
           end
@@ -200,7 +236,11 @@ describe ApplicationController do
 
         context 'when the request format is neither atom nor ics' do
           it "doesn't log the user in" do
+            expect(authentication_metrics)
+              .to increment(:user_unauthenticated_counter)
+
             get :index, feed_token: user.feed_token
+
             expect(response.status).not_to have_gitlab_http_status 200
             expect(response.body).not_to eq 'authenticated'
           end
@@ -209,7 +249,11 @@ describe ApplicationController do
 
       context "when the 'feed_token' param is populated with an invalid feed token" do
         it "doesn't log the user" do
+          expect(authentication_metrics)
+            .to increment(:user_unauthenticated_counter)
+
           get :index, feed_token: 'token', format: :atom
+
           expect(response.status).not_to eq 200
           expect(response.body).not_to eq 'authenticated'
         end

spec/lib/gitlab/auth/activity_spec.rb

+require 'fast_spec_helper'
+
+describe Gitlab::Auth::Activity do
+  describe '.each_counter' do
+    it 'has all static counters defined' do
+      described_class.each_counter do |counter|
+        expect(described_class).to respond_to(counter)
+      end
+    end
+
+    it 'has all static incrementers defined' do
+      described_class.each_counter do |counter|
+        expect(described_class).to respond_to("#{counter}_increment!")
+      end
+    end
+
+    it 'has all counters starting with `user_`' do
+      described_class.each_counter do |counter|
+        expect(counter).to start_with('user_')
+      end
+    end
+
+    it 'yields counter method, name and description' do
+      described_class.each_counter do |method, name, description|
+        expect(method).to eq "#{name}_counter"
+        expect(description).to start_with('Counter of')
+      end
+    end
+  end
+end

spec/lib/gitlab/auth/blocked_user_tracker_spec.rb

@@ -3,24 +3,30 @@ require 'spec_helper'
 describe Gitlab::Auth::BlockedUserTracker do
   set(:user) { create(:user) }
 
-  describe '.log_if_user_blocked' do
+  describe '#log_blocked_user_activity!' do
     it 'does not log if user failed to login due to undefined reason' do
       expect_any_instance_of(SystemHooksService).not_to receive(:execute_hooks_for)
 
-      expect(described_class.log_if_user_blocked({})).to be_nil
+      tracker = described_class.new({})
+
+      expect(tracker.user).to be_nil
+      expect(tracker.user_blocked?).to be_falsey
+      expect(tracker.log_blocked_user_activity!).to be_nil
     end
 
     it 'gracefully handles malformed environment variables' do
-      env = { 'warden.options' => 'test' }
+      tracker = described_class.new({ 'warden.options' => 'test' })
 
-      expect(described_class.log_if_user_blocked(env)).to be_nil
+      expect(tracker.user).to be_nil
+      expect(tracker.user_blocked?).to be_falsey
+      expect(tracker.log_blocked_user_activity!).to be_nil
     end
 
     context 'failed login due to blocked user' do
       let(:base_env) { { 'warden.options' => { message: User::BLOCKED_MESSAGE } } }
       let(:env) { base_env.merge(request_env) }
 
-      subject { described_class.log_if_user_blocked(env) }
+      subject { described_class.new(env) }
 
       before do
         expect_any_instance_of(SystemHooksService).to receive(:execute_hooks_for).with(user, :failed_login)
@@ -32,14 +38,17 @@ describe Gitlab::Auth::BlockedUserTracker do
         it 'logs a blocked user' do
           user.block!
 
-          expect(subject).to be_truthy
+          expect(subject.user).to be_blocked
+          expect(subject.user_blocked?).to be true
+          expect(subject.log_blocked_user_activity!).to be_truthy
         end
 
         it 'logs a blocked user by e-mail' do
           user.block!
           env[described_class::ACTIVE_RECORD_REQUEST_PARAMS]['user']['login'] = user.email
 
-          expect(subject).to be_truthy
+          expect(subject.user).to be_blocked
+          expect(subject.log_blocked_user_activity!).to be_truthy
         end
       end
 
@@ -49,13 +58,17 @@ describe Gitlab::Auth::BlockedUserTracker do
         it 'logs a blocked user' do
           user.block!
 
-          expect(subject).to be_truthy
+          expect(subject.user).to be_blocked
+          expect(subject.user_blocked?).to be true
+          expect(subject.log_blocked_user_activity!).to be_truthy
         end
 
         it 'logs a LDAP blocked user' do
           user.ldap_block!
 
-          expect(subject).to be_truthy
+          expect(subject.user).to be_blocked
+          expect(subject.user_blocked?).to be true
+          expect(subject.log_blocked_user_activity!).to be_truthy
         end
       end
     end

spec/support/helpers/stub_metrics.rb

+module StubMetrics
+  def authentication_metrics
+    Gitlab::Auth::Activity
+  end
+
+  def stub_authentication_activity_metrics(debug: false)
+    authentication_metrics.each_counter do |name, metric, description|
+      allow(authentication_metrics).to receive(name)
+        .and_return(double("#{metric} - #{description}"))
+    end
+
+    debug_authentication_activity_metrics if debug
+  end
+
+  def debug_authentication_activity_metrics
+    authentication_metrics.tap do |metrics|
+      metrics.each_counter do |name, metric|
+        "#{name}_increment!".tap do |incrementer|
+          allow(metrics).to receive(incrementer).and_wrap_original do |method|
+            puts "Authentication activity metric incremented: #{name}"
+            method.call
+          end
+        end
+      end
+    end
+  end
+end

spec/support/matchers/metric_counter_matcher.rb

+RSpec::Matchers.define :increment do |counter|
+  match do |adapter|
+    expect(adapter.send(counter))
+      .to receive(:increment)
+      .exactly(@exactly || :once)
+  end
+
+  chain :twice do
+    @exactly = :twice
+  end
+end

spec/support/rspec.rb

 require_relative "helpers/stub_configuration"
+require_relative "helpers/stub_metrics"
 require_relative "helpers/stub_object_storage"
 require_relative "helpers/stub_env"
 
@@ -7,6 +8,7 @@ RSpec.configure do |config|
   config.raise_errors_for_deprecations!
 
   config.include StubConfiguration
+  config.include StubMetrics
   config.include StubObjectStorage
   config.include StubENV