RUBY-2320 Configure how many backtrace lines are shown in monitor exceptions

docs/tutorials/ruby-driver-create-client.txt

@@ -301,6 +301,15 @@ Ruby Options
      - ``Hash``
      - none
 
+   * - ``:bg_error_backtrace``
+     - Experimental. Controls whether and how backtraces are logged when
+       errors occur in background threads. If ``true``, the driver will log
+       complete backtraces. If set to a positive integer, the driver will
+       log up to that many backtrace lines. If set to ``false`` or ``nil``,
+       no backtraces will be logged. Other values are an error.
+     - ``true``, ``false``, ``nil``, ``Integer``
+     - none
+
    * - ``:compressors``
      - A list of potential compressors to use, in order of preference. The driver chooses the first
        compressor that is also supported by the server. Currently the driver only supports 'zlib'.

lib/mongo.rb

@@ -55,9 +55,11 @@
 require 'mongo/database'
 require 'mongo/crypt'
 require 'mongo/client' # Purposely out-of-order so that database is loaded first
+require 'mongo/client_encryption'
 require 'mongo/dbref'
 require 'mongo/grid'
 require 'mongo/index'
+require 'mongo/lint'
 require 'mongo/server'
 require 'mongo/server_selector'
 require 'mongo/session'
@@ -67,5 +69,4 @@
 require 'mongo/uri'
 require 'mongo/version'
 require 'mongo/write_concern'
-require 'mongo/lint'
-require 'mongo/client_encryption'
+require 'mongo/utils'

lib/mongo/client.rb

@@ -55,6 +55,7 @@ class Client
       :auth_mech_properties,
       :auth_source,
       :auto_encryption_options,
+      :bg_error_backtrace,
       :cleanup,
       :compressors,
       :direct_connection,
@@ -213,6 +214,10 @@ def hash
     #   use. One of :mongodb_cr, :mongodb_x509, :plain, :scram, :scram256
     # @option options [ Hash ] :auth_mech_properties
     # @option options [ String ] :auth_source The source to authenticate from.
+    # @option options [ true | false | nil | Integer ] :bg_error_backtrace
+    #   Experimental. Set to true to log complete backtraces for errors in
+    #   background threads. Set to false or nil to not log backtraces. Provide
+    #   a positive integer to log up to that many backtrace lines.
     # @option options [ Array<String> ] :compressors A list of potential
     #   compressors to use, in order of preference. The driver chooses the
     #   first compressor that is also supported by the server. Currently the
@@ -1131,6 +1136,19 @@ def validate_options!(addresses = nil)
       if options[:direct_connection] == false && options[:connect] && options[:connect].to_sym == :direct
         raise ArgumentError, "Conflicting client options: direct_connection=false and connect=#{options[:connect]}"
       end
+
+      if value = options[:bg_error_backtrace]
+        case value
+        when Integer
+          if value <= 0
+            raise ArgumentError, ":bg_error_backtrace option value must be true, false, nil or a positive integer: #{value}"
+          end
+        when true
+          # OK
+        else
+          raise ArgumentError, ":bg_error_backtrace option value must be true, false, nil or a positive integer: #{value}"
+        end
+      end
     end
 
     # Validates all authentication-related options after they are set on the client

lib/mongo/server/monitor.rb

@@ -230,7 +230,12 @@ def do_scan
         begin
           result = ismaster
         rescue => exc
-          log_warn("Error running ismaster on #{server.address}: #{exc.class}: #{exc}:\n#{exc.backtrace[0..5].join("\n")}")
+          msg = "Error running ismaster on #{server.address}"
+          Utils.warn_monitor_exception(msg, exc,
+            logger: options[:logger],
+            log_prefix: options[:log_prefix],
+            bg_error_backtrace: options[:bg_error_backtrace],
+          )
           if monitoring.monitoring?
             monitoring.failed(
               Monitoring::SERVER_HEARTBEAT,

lib/mongo/server/monitor/connection.rb

@@ -206,8 +206,13 @@ def handshake!
           set_compressor!(reply)
           @server_connection_id = reply['connectionId']
           reply
-        rescue => e
-          log_warn("Failed to handshake with #{address}: #{e.class}: #{e}:\n#{e.backtrace[0..5].join("\n")}")
+        rescue => exc
+          msg = "Failed to handshake with #{address}"
+          Utils.warn_monitor_exception(msg, exc,
+            logger: options[:logger],
+            log_prefix: options[:log_prefix],
+            bg_error_backtrace: options[:bg_error_backtrace],
+          )
           raise
         end
 

lib/mongo/server/pending_connection.rb

@@ -116,8 +116,13 @@ def handshake!(speculative_auth_doc: nil)
                 Protocol::Message.deserialize(socket, Protocol::Message::MAX_MESSAGE_SIZE).documents.first
               end
             end
-          rescue => e
-            log_warn("Failed to handshake with #{address}: #{e.class}: #{e}:\n#{e.backtrace[0..5].join("\n")}")
+          rescue => exc
+            msg = "Failed to handshake with #{address}"
+            Utils.warn_monitor_exception(msg, exc,
+              logger: options[:logger],
+              log_prefix: options[:log_prefix],
+              bg_error_backtrace: options[:bg_error_backtrace],
+            )
             raise
           end
         end
@@ -151,8 +156,13 @@ def authenticate!(
                 speculative_auth_result: speculative_auth_result,
               )
               auth.login
-            rescue => e
-              log_warn("Failed to authenticate to #{address}: #{e.class}: #{e}:\n#{e.backtrace[0..5].join("\n")}")
+            rescue => exc
+              msg = "Failed to authenticate to #{address}"
+              Utils.warn_monitor_exception(msg, exc,
+                logger: options[:logger],
+                log_prefix: options[:log_prefix],
+                bg_error_backtrace: options[:bg_error_backtrace],
+              )
               raise
             end
           end

lib/mongo/utils.rb

@@ -0,0 +1,58 @@
+# Copyright (C) 2020 MongoDB Inc.
+#
+# Licensed under the Apache License, Version 2.0 (the 'License');
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#   http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an 'AS IS' BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+module Mongo
+
+  # @api private
+  module Utils
+
+    class LocalLogger
+      include Loggable
+
+      def initialize(**opts)
+        @options = opts
+      end
+
+      attr_reader :options
+    end
+
+    # @option opts [ true | false | nil | Integer ] :bg_error_backtrace
+    #   Experimental. Set to true to log complete backtraces for errors in
+    #   background threads. Set to false or nil to not log backtraces. Provide
+    #   a positive integer to log up to that many backtrace lines.
+    # @option opts [ Logger ] :logger A custom logger to use.
+    # @option opts [ String ] :log_prefix A custom log prefix to use when
+    #   logging.
+    module_function def warn_monitor_exception(msg, exc, **opts)
+      bt_excerpt = excerpt_backtrace(exc, **opts)
+      logger = LocalLogger.new(opts)
+      logger.log_warn("#{msg}: #{exc.class}: #{exc}#{bt_excerpt}")
+    end
+
+    # @option opts [ true | false | nil | Integer ] :bg_error_backtrace
+    #   Experimental. Set to true to log complete backtraces for errors in
+    #   background threads. Set to false or nil to not log backtraces. Provide
+    #   a positive integer to log up to that many backtrace lines.
+    module_function def excerpt_backtrace(exc, **opts)
+      case lines = opts[:bg_error_backtrace]
+      when Integer
+        ":\n#{exc.backtrace[0..lines].join("\n")}"
+      when false, nil
+        nil
+      else
+        ":\n#{exc.backtrace.join("\n")}"
+      end
+    end
+  end
+end

spec/mongo/client_construction_spec.rb

@@ -1138,6 +1138,48 @@
         end
       end
 
+      context ':bg_error_backtrace option' do
+        [true, false, nil, 42].each do |valid_value|
+          context "valid value: #{valid_value.inspect}" do
+            let(:options) do
+              {bg_error_backtrace: valid_value}
+            end
+
+            it 'is accepted' do
+              client.options[:bg_error_backtrace].should == valid_value
+            end
+          end
+        end
+
+        context 'invalid value type' do
+          let(:options) do
+            {bg_error_backtrace: 'yes'}
+          end
+
+          it 'is rejected' do
+            lambda do
+              client
+            end.should raise_error(ArgumentError, /:bg_error_backtrace option value must be true, false, nil or a positive integer/)
+          end
+        end
+
+        context 'invalid value' do
+          [0, -1, 42.0].each do |invalid_value|
+            context "invalid value: #{invalid_value.inspect}" do
+              let(:options) do
+                {bg_error_backtrace: invalid_value}
+              end
+
+              it 'is rejected' do
+                lambda do
+                  client
+                end.should raise_error(ArgumentError, /:bg_error_backtrace option value must be true, false, nil or a positive integer/)
+              end
+            end
+          end
+        end
+      end
+
       describe ':read option' do
         [
           :primary, :primary_preferred, :secondary, :secondary_preferred,  :nearest
@@ -1265,46 +1307,46 @@
       context 'when the block raises an error' do
         it 'it is closed after the block' do
           block_client_raise = nil
-          expect do  
+          expect do
             Mongo::Client.new(
               SpecConfig.instance.addresses,
               SpecConfig.instance.test_options.merge(database: SpecConfig.instance.test_db),
             ) do |client|
               block_client_raise = client
               raise "This is an error!"
             end
-          end.to raise_error(StandardError, "This is an error!")  
+          end.to raise_error(StandardError, "This is an error!")
           expect(block_client_raise.cluster.connected?).to eq(false)
         end
       end
 
       context 'when the hosts given include the protocol' do
         it 'raises an error on mongodb://' do
-          expect do 
+          expect do
             Mongo::Client.new(['mongodb://127.0.0.1:27017/test'])
           end.to raise_error(ArgumentError, "Host 'mongodb://127.0.0.1:27017/test' should not contain protocol. Did you mean to not use an array?")
         end
 
         it 'raises an error on mongodb+srv://' do
-          expect do 
+          expect do
             Mongo::Client.new(['mongodb+srv://127.0.0.1:27017/test'])
           end.to raise_error(ArgumentError, "Host 'mongodb+srv://127.0.0.1:27017/test' should not contain protocol. Did you mean to not use an array?")
         end
 
         it 'raises an error on multiple items' do
-          expect do 
+          expect do
             Mongo::Client.new(['127.0.0.1:27017', 'mongodb+srv://127.0.0.1:27017/test'])
           end.to raise_error(ArgumentError, "Host 'mongodb+srv://127.0.0.1:27017/test' should not contain protocol. Did you mean to not use an array?")
         end
 
         it 'raises an error only at beginning of string' do
-          expect do 
+          expect do
             Mongo::Client.new(['somethingmongodb://127.0.0.1:27017/test', 'mongodb+srv://127.0.0.1:27017/test'])
           end.to raise_error(ArgumentError, "Host 'mongodb+srv://127.0.0.1:27017/test' should not contain protocol. Did you mean to not use an array?")
         end
 
         it 'raises an error with different case' do
-          expect do 
+          expect do
             Mongo::Client.new(['MongOdB://127.0.0.1:27017/test'])
           end.to raise_error(ArgumentError, "Host 'MongOdB://127.0.0.1:27017/test' should not contain protocol. Did you mean to not use an array?")
         end

spec/runners/change_streams/test.rb

@@ -107,7 +107,7 @@ def teardown_test
 
       def run
         change_stream = begin
-          @target.watch(@pipeline, Utils.snakeize_hash(@options))
+          @target.watch(@pipeline, ::Utils.snakeize_hash(@options))
         rescue Mongo::Error::OperationFailure => e
           return {
             result: {

spec/runners/cmap.rb

@@ -40,7 +40,7 @@ def initialize(test_path)
         @test = YAML.load(File.read(test_path))
 
         @description = @test['description']
-        @pool_options = Utils.snakeize_hash(process_options(@test['poolOptions']))
+        @pool_options = ::Utils.snakeize_hash(process_options(@test['poolOptions']))
         @spec_ops = @test['operations'].map { |o| Operation.new(self, o) }
         @processed_ops = []
         @expected_error = @test['error']

spec/runners/command_monitoring.rb

@@ -135,7 +135,7 @@ def hash_matches?(actual, expected)
         if expected.keys.first == '$numberLong'
           converted = expected.values.first.to_i
           if actual.is_a?(BSON::Int64)
-            actual = Utils.int64_value(actual)
+            actual = ::Utils.int64_value(actual)
           elsif actual.is_a?(BSON::Int32)
             return false
           end

spec/runners/crud/operation.rb

@@ -88,7 +88,7 @@ def has_results?
       #
       # @since 2.0.0
       def execute(target)
-        op_name = Utils.underscore(name)
+        op_name = ::Utils.underscore(name)
         if target.is_a?(Mongo::Database)
           op_name = "db_#{op_name}"
         elsif target.is_a?(Mongo::Client)
@@ -99,14 +99,14 @@ def execute(target)
 
       def database_options
         if opts = @spec['databaseOptions']
-          Utils.convert_operation_options(opts)
+          ::Utils.convert_operation_options(opts)
         else
           nil
         end
       end
 
       def collection_options
-        Utils.convert_operation_options(@spec['collectionOptions'])
+        ::Utils.convert_operation_options(@spec['collectionOptions'])
       end
 
       private
@@ -371,7 +371,7 @@ def options
         # bulk write test is an exception in that it has an "options" key
         # with the options.
         arguments.merge(arguments['options'] || {}).each do |spec_k, v|
-          ruby_k = Utils.underscore(spec_k).to_sym
+          ruby_k = ::Utils.underscore(spec_k).to_sym
 
           if v.is_a?(Hash) && v['$numberLong']
             v = v['$numberLong'].to_i
@@ -401,8 +401,8 @@ def requests
       end
 
       def bulk_request(request)
-        op_name = Utils.underscore(request['name'])
-        args = Utils.shallow_snakeize_hash(request['arguments'])
+        op_name = ::Utils.underscore(request['name'])
+        args = ::Utils.shallow_snakeize_hash(request['arguments'])
         if args[:document]
           unless args.keys == [:document]
             raise "If :document is given, it must be the only key"
@@ -417,15 +417,15 @@ def upsert
       end
 
       def transform_return_document(v)
-        Utils.underscore(v).to_sym
+        ::Utils.underscore(v).to_sym
       end
 
       def update
         arguments['update']
       end
 
       def transform_read_preference(v)
-        Utils.snakeize_hash(v)
+        ::Utils.snakeize_hash(v)
       end
 
       def read_preference

spec/runners/crud/test.rb

@@ -28,7 +28,7 @@ def initialize(crud_spec, data, test)
         @spec = crud_spec
         @data = data
         @description = test['description']
-        @client_options = Utils.convert_client_options(test['clientOptions'] || {})
+        @client_options = ::Utils.convert_client_options(test['clientOptions'] || {})
 
         if test['failPoint']
           @fail_point_command = FAIL_POINT_BASE_COMMAND.merge(test['failPoint'])