Merge pull request rapid7#20469 from adfoster-r7/improve-kerberos-file-load-error-messages

Improve Kerberos file load error messages

Author: cgranleese-r7

lib/msf/core/exploit/remote/kerberos/service_authenticator/base.rb

@@ -157,8 +157,9 @@ def initialize(
     credential = nil
     if cache_file.present?
       # the cache file is only used for loading credentials, it is *not* written to
-      credential = load_credential_from_file(cache_file, sname: nil, sname_hostname: @hostname)
-      serviceclass = build_spn.name_string.first
+      load_sname_hostname_credential_result = load_credential_from_file(cache_file, sname: nil, sname_hostname: @hostname)
+      credential = load_sname_hostname_credential_result[:credential]
+      serviceclass = build_spn&.name_string&.first
       if credential && credential.server.components[0] != serviceclass
         old_sname = credential.server.components.snapshot.join('/')
         credential.server.components[0] = serviceclass
@@ -168,9 +169,18 @@ def initialize(
         ticket.sname.name_string[0] = serviceclass
         credential.ticket = ticket.encode
       elsif credential.nil? && hostname.present?
-        credential = load_credential_from_file(cache_file, sname: "krbtgt/#{hostname.split('.', 2).last}")
+        load_sname_krbtgt_hostname_credential_result = load_credential_from_file(cache_file, sname: "krbtgt/#{hostname.split('.', 2).last}")
+        credential = load_sname_krbtgt_hostname_credential_result[:credential]
       end
       if credential.nil?
+        print_error("Failed to load a usable credential from ticket file: #{cache_file}")
+        print_error("Attempt failed to find a valid credential in #{cache_file} for #{load_sname_hostname_credential_result[:filter].map { |k, v| "#{k}=#{v.inspect}" }.join(', ')}:")
+        print_error(load_sname_hostname_credential_result[:filter_reasons].join("\n").indent(2))
+
+        if load_sname_krbtgt_hostname_credential_result
+          print_error("Attempt failed to find a valid credential in #{cache_file} for #{load_sname_krbtgt_hostname_credential_result[:filter].map { |k, v| "#{k}=#{v.inspect}" }.join(', ')}")
+          print_error(load_sname_krbtgt_hostname_credential_result[:filter_reasons].join("\n").indent(2))
+        end
         raise ::Rex::Proto::Kerberos::Model::Error::KerberosError.new("Failed to load a usable credential from ticket file: #{cache_file}")
       end
       print_status("Loaded a credential from ticket file: #{cache_file}")
@@ -362,7 +372,7 @@ def build_spn(options = {})
   # @return [Rex::Proto::Kerberos::CredentialCache::Krb5CcacheCredential] The ccache credential
   def request_tgt_only(options = {})
     if options[:cache_file]
-      credential = load_credential_from_file(options[:cache_file])
+      credential = load_credential_from_file(options[:cache_file])&.fetch(:credential, nil)
     else
       credential = get_cached_credential(
         options.merge(
@@ -1058,64 +1068,72 @@ def get_cached_credential(options = {})
   # Load a credential object from a file for authentication. Credentials in the file will be filtered by multiple
   # attributes including their timestamps to ensure that the returned credential appears usable.
   #
-  # @param [String] file_path The file path to load a credential object from
-  # @return [Rex::Proto::Kerberos::CredentialCache::Krb5CacheCredential] the credential object for authentication
-  def load_credential_from_file(file_path, options = {})
-    unless File.readable?(file_path.to_s)
-      wlog("Failed to load ticket file '#{file_path}' (file not readable)")
+  # @param [String] path The path to load a credential object from
+  # @return [Hash] :credential [Rex::Proto::Kerberos::CredentialCache::Krb5CacheCredential] the credential object for authentication
+  # @return [Hash] :filter_reasons [Array<String>] the reasons for filtering tickets
+  def load_credential_from_file(path, options = {})
+    unless File.readable?(path.to_s)
       return nil
     end
 
     begin
-      cache = Rex::Proto::Kerberos::CredentialCache::Krb5Ccache.read(File.binread(file_path))
+      cache = Rex::Proto::Kerberos::CredentialCache::Krb5Ccache.read(File.binread(path))
     rescue StandardError => e
-      elog("Failed to load ticket file '#{file_path}' (parsing failed)", error: e)
+      elog("Failed to load ticket file '#{path}' (parsing failed)", error: e)
       return nil
     end
 
     sname = options.fetch(:sname) { build_spn&.to_s }
     sname_hostname = options.fetch(:sname_hostname, nil)
     now = Time.now.utc
 
+    filter = {
+      realm: @realm,
+      sname: sname,
+      sname_hostname: sname_hostname
+    }.merge(options)
+    filter_reasons = []
+
     cache.credentials.to_ary.each.with_index(1) do |credential, index|
       tkt_start = credential.starttime == Time.at(0).utc ? credential.authtime : credential.starttime
       tkt_end = credential.endtime
+      filter_reason_prefix = "Filtered credential #{path} ##{index} reason: "
 
       unless tkt_start < now
-        wlog("Filtered credential #{file_path} ##{index} reason: Ticket start time is before now (start: #{tkt_start})")
+        filter_reasons << "#{filter_reason_prefix}Ticket start time is before now (start: #{tkt_start})"
         next
       end
 
       unless now < tkt_end
-        wlog("Filtered credential #{file_path} ##{index} reason: Ticket is expired (expiration: #{tkt_end})")
+        filter_reasons << "#{filter_reason_prefix}Ticket is expired (expiration: #{tkt_end})"
         next
       end
 
       unless !@realm || @realm.casecmp?(credential.server.realm.to_s)
-        wlog("Filtered credential #{file_path} ##{index} reason: Realm (#{@realm}) does not match (realm: #{credential.server.realm})")
+        filter_reasons << "#{filter_reason_prefix} Realm (#{@realm}) does not match (realm: #{credential.server.realm})"
         next
       end
 
       unless !sname || sname.to_s.casecmp?(credential.server.components.snapshot.join('/'))
-        wlog("Filtered credential #{file_path} ##{index} reason: SPN (#{sname}) does not match (spn: #{credential.server.components.snapshot.join('/')})")
+        filter_reasons << "#{filter_reason_prefix}SPN (#{sname}) does not match (spn: #{credential.server.components.snapshot.join('/')})"
         next
       end
 
       unless !sname_hostname ||
-          sname_hostname.to_s.downcase == credential.server.components[1].downcase ||
-          sname_hostname.to_s.downcase.ends_with?('.' + credential.server.components[1].downcase)
-        wlog("Filtered credential #{file_path} ##{index} reason: SPN (#{sname_hostname}) hostname does not match (spn: #{credential.server.components.snapshot.join('/')})")
+             sname_hostname.to_s.downcase == credential.server.components[1].downcase ||
+             sname_hostname.to_s.downcase.ends_with?('.' + credential.server.components[1].downcase)
+        filter_reasons << "#{filter_reason_prefix}SPN (#{sname_hostname}) hostname does not match (spn: #{credential.server.components.snapshot.join('/')})"
         next
       end
 
       unless !@username || @username.casecmp?(credential.client.components.last.to_s)
-        wlog("Filtered credential #{file_path} ##{index} reason: Username (#{@username}) does not match (username: #{credential.client.components.last})")
+        filter_reasons << "Filtered credential #{path} ##{index} reason: Username (#{@username}) does not match (username: #{credential.client.components.last})"
         next
       end
 
-      return credential
+      return { credential: credential, filter: filter,  filter_reasons: filter_reasons }
     end
 
-    nil
+    { credential: nil, filter: filter, filter_reasons: filter_reasons }
   end
 end

spec/file_fixtures/ccache/administrator_dev_demo_local_expired.ccache

@@ -2,7 +2,9 @@
 require 'spec_helper'
 
 RSpec.describe Msf::Exploit::Remote::Kerberos::ServiceAuthenticator::Base do
-  let(:params) {
+  include_context 'Msf::UIDriver'
+
+  let(:default_params) {
     {
       realm: 'demo.local',
       hostname: 'mock_hostname',
@@ -11,22 +13,56 @@
       host: '127.0.0.1',
       port: 88,
       timeout: 25,
-      framework: instance_double(::Msf::Framework),
-      framework_module: instance_double(::Msf::Module)
+      framework:,
+      framework_module:
     }
   }
 
+  let(:framework) do
+    instance_double(::Msf::Framework)
+  end
+
+  let(:framework_module) do
+    instance_double(::Msf::Module, framework:)
+  end
+
+  let(:params) do
+    default_params
+  end
+
   subject do
     described_class.new(**params)
   end
 
-  describe '#connect' do
-    before(:each) do
-      allow(params[:framework_module]).to receive(:framework)
-      allow(params[:framework_module]).to receive(:print_status)
-      allow(params[:framework_module]).to receive(:vprint_status)
+  def fixture(name)
+    File.join(FILE_FIXTURES_PATH, 'ccache', "#{name}.ccache")
+  end
+
+  before(:each) do
+    capture_logging(framework_module, capture_verbose: true)
+  end
+
+  describe '#initialize' do
+    context 'when a cache_file is provided' do
+      let(:params) do
+        default_params.merge({ cache_file: fixture(:fake_user_example_local_forged_silver) })
+      end
+
+      it 'raises an error and logs details' do
+        expect { subject }.to raise_error(/Failed to load a usable credential from ticket/)
+
+       expect(@combined_output.join("\n")).to match_table <<~TABLE
+         Failed to load a usable credential from ticket file: #{params[:cache_file]}
+         Attempt failed to find a valid credential in #{params[:cache_file]} for realm="demo.local", sname=nil, sname_hostname="mock_hostname":
+           Filtered credential #{params[:cache_file]} #1 reason:  Realm (demo.local) does not match (realm: EXAMPLE.LOCAL)
+         Attempt failed to find a valid credential in #{params[:cache_file]} for realm="demo.local", sname="krbtgt/mock_hostname", sname_hostname=nil
+           Filtered credential #{params[:cache_file]} #1 reason:  Realm (demo.local) does not match (realm: EXAMPLE.LOCAL)
+        TABLE
+      end
     end
+  end
 
+  describe '#connect' do
     context 'when host is nil' do
       it 'resolves it to a hostname' do
         expect(::Rex::Socket).to receive(:getresources).with("_kerberos._tcp.#{params[:realm]}", :SRV).and_return(['mock_host'])
@@ -83,4 +119,52 @@
       end
     end
   end
+
+  describe '#load_credential_from_file' do
+    context 'when a valid ticket is found' do
+      let(:params) do
+        default_params.merge({ realm: 'example.local', username: 'fake_user' })
+      end
+
+      it 'returns a valid credential that matches' do
+        expected = hash_including(
+          {
+            credential: instance_of(Rex::Proto::Kerberos::CredentialCache::Krb5CcacheCredential),
+            filter_reasons: []
+          }
+        )
+        expect(subject.send(:load_credential_from_file, fixture(:fake_user_example_local_forged_silver))).to match(expected)
+      end
+    end
+
+    context 'when the credential is not valid' do
+      it 'returns nil if the file does not exist' do
+        expect(subject.send(:load_credential_from_file, nil)).to eq nil
+      end
+
+      it 'returns filter reasons for expired tickets' do
+        expected = hash_including(
+          {
+            credential: nil,
+            filter_reasons: [
+              match(/Filtered credential.*Ticket is expired.*/)
+            ]
+          }
+        )
+        expect(subject.send(:load_credential_from_file, fixture(:administrator_dev_demo_local_expired))).to match(expected)
+      end
+
+      it 'returns filter reasons for incorrect realms' do
+        expected = hash_including(
+          {
+            credential: nil,
+            filter_reasons: [
+              match(/Filtered credential.*Realm \(demo.local\) does not match \(realm: EXAMPLE.LOCAL\).*/)
+            ]
+          }
+        )
+        expect(subject.send(:load_credential_from_file, fixture(:fake_user_example_local_forged_silver))).to match(expected)
+      end
+    end
+  end
 end

spec/file_fixtures/ccache/fake_user_example_local_forged_silver.ccache

@@ -27,7 +27,7 @@ def reset_logging!
     @combined_output = []
   end
 
-  def capture_logging(target)
+  def capture_logging(target, capture_verbose: false)
     append_output = proc do |string = ''|
       lines = string.split("\n")
       @output ||= []
@@ -48,6 +48,11 @@ def capture_logging(target)
     allow(target).to receive(:print_status, &append_output)
     allow(target).to receive(:print_good, &append_output)
 
+    if capture_verbose
+      allow(target).to receive(:vprint_status, &append_output)
+      allow(target).to receive(:vprint_error, &append_error)
+    end
+
     allow(target).to receive(:print_warning, &append_error)
     allow(target).to receive(:print_error, &append_error)
     allow(target).to receive(:print_bad, &append_error)