RUBY-1933 Add debug level logging around initial DNS seed list query (mongodb#2904)

* RUBY-1933 Log when attempting to resolve a srv hostname

* method comments

Author: jamis

lib/mongo/client.rb

@@ -502,35 +502,15 @@ def hash
     def initialize(addresses_or_uri, options = nil)
       options = options ? options.dup : {}
 
-      srv_uri = nil
-      if addresses_or_uri.is_a?(::String)
-        uri = URI.get(addresses_or_uri, options)
-        if uri.is_a?(URI::SRVProtocol)
-          # If the URI is an SRV URI, note this so that we can start
-          # SRV polling if the topology is a sharded cluster.
-          srv_uri = uri
-        end
-        addresses = uri.servers
-        uri_options = uri.client_options.dup
-        # Special handing for :write and :write_concern: allow client Ruby
-        # options to override URI options, even when the Ruby option uses the
-        # deprecated :write key and the URI option uses the current
-        # :write_concern key
-        if options[:write]
-          uri_options.delete(:write_concern)
-        end
-        options = uri_options.merge(options)
-        @srv_records = uri.srv_records
-      else
-        addresses = addresses_or_uri
-        addresses.each do |addr|
-          if addr =~ /\Amongodb(\+srv)?:\/\//i
-            raise ArgumentError, "Host '#{addr}' should not contain protocol. Did you mean to not use an array?"
-          end
-        end
+      processed = process_addresses(addresses_or_uri, options)
 
-        @srv_records = nil
-      end
+      uri = processed[:uri]
+      addresses = processed[:addresses]
+      options = processed[:options]
+
+      # If the URI is an SRV URI, note this so that we can start
+      # SRV polling if the topology is a sharded cluster.
+      srv_uri = uri if uri.is_a?(URI::SRVProtocol)
 
       options = self.class.canonicalize_ruby_options(options)
 
@@ -1217,6 +1197,73 @@ def timeout_sec
 
     private
 
+    # Attempts to parse the given list of addresses, using the provided options.
+    #
+    # @param [ String | Array<String> ] addresses the list of addresses
+    # @param [ Hash ] options the options that may drive how the list is
+    #   processed.
+    #
+    # @return [ Hash<:uri, :addresses, :options> ] the results of processing the
+    #   list of addresses.
+    def process_addresses(addresses, options)
+      if addresses.is_a?(String)
+        process_addresses_string(addresses, options)
+      else
+        process_addresses_array(addresses, options)
+      end
+    end
+
+    # Attempts to parse the given list of addresses, using the provided options.
+    #
+    # @param [ String ] addresses the list of addresses
+    # @param [ Hash ] options the options that may drive how the list is
+    #   processed.
+    #
+    # @return [ Hash<:uri, :addresses, :options> ] the results of processing the
+    #   list of addresses.
+    def process_addresses_string(addresses, options)
+      {}.tap do |processed|
+        processed[:uri] = uri = URI.get(addresses, options)
+        processed[:addresses] = uri.servers
+
+        uri_options = uri.client_options.dup
+        # Special handing for :write and :write_concern: allow client Ruby
+        # options to override URI options, even when the Ruby option uses the
+        # deprecated :write key and the URI option uses the current
+        # :write_concern key
+        if options[:write]
+          uri_options.delete(:write_concern)
+        end
+
+        processed[:options] = uri_options.merge(options)
+
+        @srv_records = uri.srv_records
+      end
+    end
+
+    # Attempts to parse the given list of addresses, using the provided options.
+    #
+    # @param [ Array<String> ] addresses the list of addresses
+    # @param [ Hash ] options the options that may drive how the list is
+    #   processed.
+    #
+    # @return [ Hash<:uri, :addresses, :options> ] the results of processing the
+    #   list of addresses.
+    def process_addresses_array(addresses, options)
+      {}.tap do |processed|
+        processed[:addresses] = addresses
+        processed[:options] = options
+
+        addresses.each do |addr|
+          if addr =~ /\Amongodb(\+srv)?:\/\//i
+            raise ArgumentError, "Host '#{addr}' should not contain protocol. Did you mean to not use an array?"
+          end
+        end
+
+        @srv_records = nil
+      end
+    end
+
     # Create a new encrypter object using the client's auto encryption options
     def build_encrypter
       @encrypter = Crypt::AutoEncrypter.new(

lib/mongo/uri/srv_protocol.rb

@@ -147,6 +147,8 @@ def parse!(remaining)
         validate_srv_hostname(hostname)
         @query_hostname = hostname
 
+        log_debug "attempting to resolve #{hostname}"
+
         @srv_result = resolver.get_records(hostname, uri_options[:srv_service_name], uri_options[:srv_max_hosts])
         if srv_result.empty?
           raise Error::NoSRVRecords.new(NO_SRV_RECORDS % hostname)

spec/mongo/uri/srv_protocol_spec.rb

@@ -2,6 +2,7 @@
 # rubocop:todo all
 
 require 'lite_spec_helper'
+require 'support/recording_logger'
 
 describe Mongo::URI::SRVProtocol do
   require_external_connectivity
@@ -21,6 +22,18 @@
     end
   end
 
+  describe 'logging' do
+    let(:logger) { RecordingLogger.new }
+    let(:uri) { described_class.new(string, logger: logger) }
+    let(:host) { 'test5.test.build.10gen.cc' }
+    let(:string) { "#{scheme}#{host}" }
+
+    it 'logs when resolving the address' do
+      expect { uri }.not_to raise_error
+      expect(logger.contents).to include("attempting to resolve #{host}")
+    end
+  end
+
   describe 'invalid uris' do
 
     context 'when there is more than one hostname' do
@@ -228,7 +241,6 @@
   end
 
   describe 'valid uris' do
-    require_external_connectivity
 
     describe 'invalid query results' do