Fixes #39512 - Add audit logs for user login/logoff/failed attempts

app/controllers/users_controller.rb

@@ -84,7 +84,17 @@ def impersonate
       User.impersonator = User.current
       session[:user] = user.id
       success _("You impersonated user %s, to cancel the session, click the impersonation icon in the top bar.") % user.name
-      Audit.create :auditable_type => 'User', :auditable_id => user.id, :user_id => User.current.id, :action => 'impersonate', :audited_changes => {}
+      Audit.manual_event!(
+        :action => 'impersonate',
+        :auditable_type => 'User',
+        :auditable_id => user.id,
+        :auditable_name => user.to_label,
+        :actor => User.current,
+        :attribute => 'authentication',
+        :value => "User '#{User.current.login}' impersonated user '#{user.login}'",
+        :remote_address => request.remote_ip,
+        :request_uuid => request.uuid
+      )
       logger.info "User #{User.current.name} impersonated #{user.name}"
       redirect_to helpers.current_hosts_path
     else
@@ -136,28 +146,44 @@ def login
     if bruteforce_attempt?
       inline_error _("Too many tries, please try again in a few minutes.")
       log_bruteforce
+      log_authentication_event('failed_login', nil, "Blocked login attempt from #{request.remote_ip}")
       telemetry_increment_counter(:bruteforce_locked_ui_logins)
       render :layout => 'login', :status => :unauthorized
       return
     end
 
     if request.post?
+      attempted_login = params[:login].try(:[], 'login')
       backup_session_content { reset_session }
       intercept = SSO::FormIntercept.new(self)
       if intercept.available? && intercept.authenticated?
         user = intercept.current_user
       else
-        user = User.try_to_login(params[:login]['login'], params[:login]['password'])
+        user = User.try_to_login(attempted_login, params[:login]['password'])
       end
       if user.nil?
         # failed to authenticate, and/or to generate the account on the fly
         inline_error _("Incorrect username or password")
-        logger.warn("Failed login attempt from #{request.remote_ip} with username '#{params[:login].try(:[], 'login')}'")
+        logger.warn("Failed login attempt from #{request.remote_ip} with username '#{attempted_login}'")
+        log_authentication_event(
+          'failed_login',
+          nil,
+          "Failed login attempt for username '#{attempted_login}'",
+          attempted_login,
+          :actor => nil
+        )
         count_login_failure
         telemetry_increment_counter(:failed_ui_logins)
         redirect_to login_users_path
       elsif user.disabled?
         inline_error _("User account is disabled, please contact your administrator")
+        log_authentication_event(
+          'failed_login',
+          user,
+          "Failed login attempt for disabled user '#{user.login}'",
+          nil,
+          :actor => nil
+        )
         redirect_to login_users_path
       else
         # valid user
@@ -194,7 +220,17 @@ def logout
 
     TopbarSweeper.expire_cache
     sso_logout_path = get_sso_method.try(:logout_url)
-    logger.info("User '#{User.unscoped.find_by_id(session[:user]).try(:login) || session[:user]}' logged out")
+    user_id = session[:user]
+    logged_out_user = User.unscoped.find_by_id(user_id)
+    logged_out_user_login = logged_out_user.try(:login) || user_id
+    logger.info("User '#{logged_out_user_login}' logged out")
+    log_authentication_event(
+      'logout',
+      logged_out_user,
+      "User '#{logged_out_user_login}' logged out",
+      nil,
+      :auditable_id => user_id
+    )
     session[:user] = @user = User.current = nil
     if flash[:success] || flash[:info] || flash[:error]
       flash.keep
@@ -233,6 +269,7 @@ def find_resource(permission = :view_users)
 
   def login_user(user)
     logger.info("User '#{user.login}' logged in from '#{request.ip}'")
+    log_authentication_event('login', user, "User '#{user.login}' logged in")
     session[:user]         = user.id
     uri                    = session.to_hash.with_indifferent_access[:original_uri]
     session[:original_uri] = nil
@@ -243,6 +280,20 @@ def login_user(user)
     redirect_to (uri || helpers.current_hosts_path)
   end
 
+  def log_authentication_event(action, user, message, auditable_name = nil, actor: user, auditable_id: user&.id)
+    Audit.manual_event!(
+      :action => action,
+      :auditable_type => 'User',
+      :auditable_id => auditable_id,
+      :auditable_name => auditable_name || user&.to_label,
+      :actor => actor,
+      :attribute => 'authentication',
+      :value => message,
+      :remote_address => request.remote_ip,
+      :request_uuid => request.uuid
+    )
+  end
+
   def parameter_filter_context
     Foreman::Controller::Parameters::User::Context.new(:ui, controller_name, params[:action], editing_self?)
   end

app/models/concerns/audit_extensions.rb

@@ -111,10 +111,17 @@ def taxed_and_untaxed
           or(arel_table[:auditable_type].in(untaxable.map(&:to_s))).
           or(arel_table.grouping(arel_taxed_only_by_organization)).
           or(arel_table.grouping(arel_taxed_only_by_location))
+        statement = statement.or(arel_table.grouping(arel_global_failed_login)) if User.current.admin?
 
         taxonomy_join_scope.where(statement)
       end
 
+      def arel_global_failed_login
+        arel_table[:auditable_type].eq('User').
+          and(arel_table[:auditable_id].eq(nil)).
+          and(arel_table[:action].eq('failed_login'))
+      end
+
       def arel_taxed_only_by_location
         arel_table[:auditable_type].in(location_taxable.map(&:to_s)).
           and(loc_join_arel[:taxonomy_id].in(user_taxonomy_ids(Location)))
@@ -153,6 +160,25 @@ def has_taxonomix?(model)
   end
 
   module ClassMethods
+    def manual_event!(action:, auditable_type:, attribute:, value:, auditable_id: nil, auditable_name: nil,
+      actor: User.current, remote_address: nil, request_uuid: nil)
+      audit_attributes = {
+        :auditable_type => auditable_type,
+        :auditable_id => auditable_id,
+        :auditable_name => auditable_name,
+        :action => action,
+        :audited_changes => { attribute.to_s => value },
+        :remote_address => remote_address,
+        :request_uuid => request_uuid,
+      }
+
+      if actor
+        User.as(actor) { create!(audit_attributes) }
+      else
+        create_without_actor!(audit_attributes)
+      end
+    end
+
     def main_objects
       main_classes = audited_classes.reject { |cl| cl.audited_options.key?(:associated_with) }
       main_classes.concat(non_abstract_parents(main_classes))
@@ -166,6 +192,20 @@ def non_abstract_parents(classes_list)
       parents_list = classes_list.map(&:superclass).uniq
       parents_list.select { |cl| cl != ActiveRecord::Base && !cl.abstract_class? && cl.table_exists? }.compact
     end
+
+    private
+
+    # Audit callbacks copy User.current into the audit row. For actor: nil we
+    # intentionally want no actor, not an anonymous admin or a previously set
+    # current user. Clear User.current only for this create and restore it after
+    # so the caller's request/thread context is unchanged.
+    def create_without_actor!(audit_attributes)
+      previous_user = User.current
+      User.current = nil
+      create!(audit_attributes)
+    ensure
+      User.current = previous_user
+    end
   end
 
   private
@@ -189,8 +229,9 @@ def log_audit
         audited_fields[:audit_field] = change
         log_line = change
       end
+      audit_target = auditable_id.nil? ? auditable_name : auditable_id
       Foreman::Logging.with_fields(audited_fields) do
-        audit_logger.info "#{auditable_type} (#{auditable_id}) #{action} event on #{attribute} #{log_line}"
+        audit_logger.info "#{auditable_type} (#{audit_target}) #{action} event on #{attribute} #{log_line}"
       end
     end
     telemetry_increment_counter(:audit_records_logged, audited_changes.count, type: auditable_type)

test/controllers/users_controller_test.rb

@@ -417,6 +417,17 @@ class UsersControllerTest < ActionController::TestCase
     assert users(:admin).last_login_on.to_i >= time.to_i, 'User last login on was not updated'
   end
 
+  test "#login creates audit event for successful login" do
+    assert_difference -> { authentication_audits('login').count } do
+      post :login, params: { :login => {'login' => users(:admin).login, 'password' => 'secret'} }
+    end
+
+    audit = authentication_audits('login').last
+    assert_equal users(:admin).id, audit.auditable_id
+    assert_equal users(:admin).id, audit.user_id
+    assert_equal "User '#{users(:admin).login}' logged in", audit.audited_changes['authentication']
+  end
+
   test "#login resets the session ID to prevent fixation" do
     @controller.expects(:reset_session)
     post :login, params: { :login => {'login' => users(:admin).login, 'password' => 'secret'} }
@@ -430,6 +441,46 @@ class UsersControllerTest < ActionController::TestCase
     assert flash[:inline][:error].present?
   end
 
+  test "#login creates audit event for failed login" do
+    assert_difference -> { authentication_audits('failed_login').count } do
+      post :login, params: { :login => {'login' => 'missing-user', 'password' => 'password'} }
+    end
+
+    audit = authentication_audits('failed_login').last
+    assert_equal 'missing-user', audit.auditable_name
+    assert_nil audit.user_id
+    assert_equal "Failed login attempt for username 'missing-user'", audit.audited_changes['authentication']
+  end
+
+  test "#login does not resolve known user for failed login audit event" do
+    login = users(:admin).login
+    User.expects(:try_to_login).with(login, 'password').returns(nil)
+    User.expects(:unscoped).never
+
+    assert_difference -> { authentication_audits('failed_login').count } do
+      post :login, params: { :login => {'login' => login, 'password' => 'password'} }
+    end
+
+    audit = authentication_audits('failed_login').last
+    assert_nil audit.auditable_id
+    assert_equal login, audit.auditable_name
+    assert_nil audit.user_id
+    assert_equal "Failed login attempt for username '#{login}'", audit.audited_changes['authentication']
+  end
+
+  test "#login creates audit event for disabled user login" do
+    users(:one).update(disabled: true)
+    User.expects(:try_to_login).with(users(:one).login, 'password').returns(users(:one))
+    assert_difference -> { authentication_audits('failed_login').count } do
+      post :login, params: { :login => {'login' => users(:one).login, 'password' => 'password'} }
+    end
+
+    audit = authentication_audits('failed_login').last
+    assert_equal users(:one).id, audit.auditable_id
+    assert_nil audit.user_id
+    assert_equal "Failed login attempt for disabled user '#{users(:one).login}'", audit.audited_changes['authentication']
+  end
+
   test "#login prevents brute-force login attempts" do
     User.expects(:try_to_login).times(30).returns(nil)
     @controller.expects(:log_bruteforce)
@@ -439,6 +490,46 @@ class UsersControllerTest < ActionController::TestCase
     assert_equal "Too many tries, please try again in a few minutes.", flash[:inline][:error]
   end
 
+  test "#login creates audit event for blocked brute-force login" do
+    User.expects(:try_to_login).times(30).returns(nil)
+    @controller.stubs(:log_bruteforce)
+
+    30.times do
+      post :login, params: { :login => {'login' => 'admin', 'password' => 'password'} }
+    end
+
+    assert_difference -> { authentication_audits('failed_login').count } do
+      post :login, params: { :login => {'login' => 'admin', 'password' => 'password'} }
+    end
+
+    audit = authentication_audits('failed_login').last
+    assert_equal "Blocked login attempt from #{@request.remote_ip}", audit.audited_changes['authentication']
+  end
+
+  test "#logout creates audit event" do
+    assert_difference -> { authentication_audits('logout').count } do
+      post :logout, session: set_session_user(users(:admin))
+    end
+
+    audit = authentication_audits('logout').last
+    assert_equal users(:admin).id, audit.auditable_id
+    assert_equal users(:admin).id, audit.user_id
+    assert_equal "User '#{users(:admin).login}' logged out", audit.audited_changes['authentication']
+  end
+
+  test "#logout creates audit event when session user record is missing" do
+    missing_user_id = User.maximum(:id) + 1
+
+    assert_difference -> { authentication_audits('logout').count } do
+      post :logout, session: { :user => missing_user_id }
+    end
+
+    audit = authentication_audits('logout').last
+    assert_equal missing_user_id, audit.auditable_id
+    assert_nil audit.user_id
+    assert_equal "User '#{missing_user_id}' logged out", audit.audited_changes['authentication']
+  end
+
   test "#login retains taxonomy session attributes in new session" do
     post :login, params: { :login => {'login' => users(:admin).login, 'password' => 'secret'}},
          session: { :location_id => taxonomies(:location1).id,
@@ -594,9 +685,16 @@ class UsersControllerTest < ActionController::TestCase
   test "should impersonate a user" do
     session[:impersonated_by] = nil
     user = users(:one)
-    get :impersonate, params: { :id => user.id }, session: set_session_user
+    assert_difference -> { authentication_audits('impersonate').count } do
+      get :impersonate, params: { :id => user.id }, session: set_session_user
+    end
     assert_redirected_to ApplicationHelper.current_hosts_path
     assert flash.to_hash["success"]
+
+    audit = authentication_audits('impersonate').last
+    assert_equal user.id, audit.auditable_id
+    assert_equal users(:admin).id, audit.user_id
+    assert_equal "User '#{users(:admin).login}' impersonated user '#{user.login}'", audit.audited_changes['authentication']
   end
 
   test "should stop impersonating a user" do
@@ -621,4 +719,12 @@ class UsersControllerTest < ActionController::TestCase
       assert flash[:inline][:error].present?
     end
   end
+
+  private
+
+  def authentication_audits(action)
+    Audit.where(:auditable_type => 'User', :action => action).
+      where("audited_changes LIKE ?", "%authentication%").
+      order(:id)
+  end
 end

test/models/audit_test.rb

@@ -35,6 +35,38 @@ class AuditTest < ActiveSupport::TestCase
         end
       end
 
+      it 'does not include global failed login audits for non-admins when current taxonomy is set' do
+        audit = Audit.manual_event!(
+          :action => 'failed_login',
+          :auditable_type => 'User',
+          :auditable_name => 'missing-user',
+          :actor => nil,
+          :attribute => 'authentication',
+          :value => "Failed login attempt for username 'missing-user'"
+        )
+
+        Taxonomy.as_taxonomy(user_organization, user_location) do
+          assert_not_include Audit.taxed_and_untaxed.pluck(:id), audit.id
+        end
+      end
+
+      it 'includes global failed login audits for admins when current taxonomy is set' do
+        audit = Audit.manual_event!(
+          :action => 'failed_login',
+          :auditable_type => 'User',
+          :auditable_name => 'missing-user',
+          :actor => nil,
+          :attribute => 'authentication',
+          :value => "Failed login attempt for username 'missing-user'"
+        )
+
+        as_admin do
+          Taxonomy.as_taxonomy(user_organization, user_location) do
+            assert_include Audit.taxed_and_untaxed.pluck(:id), audit.id
+          end
+        end
+      end
+
       # Test single taxed records behaviour - location_taxables and organization_taxables
       { location: 'Organization', organization: 'Location' }.each do |scope, tested_model|
         context "#{scope}_taxables only" do