RUBY-1905 Indicate which server operations were attempted on and attempt number in driver-surfaced exceptions (#1508)

Author: p-mongo

lib/mongo/error.rb

@@ -12,11 +12,14 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
+require 'mongo/error/notable'
+
 module Mongo
   # Base error class for all Mongo related errors.
   #
   # @since 2.0.0
   class Error < StandardError
+    include Notable
 
     # The error code field.
     #
@@ -141,6 +144,7 @@ def add_label(label)
   end
 end
 
+require 'mongo/error/auth_error'
 require 'mongo/error/sdam_error_detection'
 require 'mongo/error/parser'
 require 'mongo/error/write_retryable'

lib/mongo/error/auth_error.rb

@@ -0,0 +1,29 @@
+# Copyright (C) 2018-2019 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
+  class Error
+
+    # Raised when authentication fails.
+    #
+    # Note: This class is derived from RuntimeError for
+    # backwards compatibility reasons. It is subject to
+    # change in future major versions of the driver.
+    #
+    # @since 2.10.1
+    class AuthError < RuntimeError
+      include Notable
+    end
+  end
+end

lib/mongo/error/bulk_write_error.rb

@@ -50,7 +50,7 @@ def to_s
         else
           ''
         end
-        self.class.name + messages
+        "#{self.class}: #{messages}" + notes_tail
       end
     end
   end

lib/mongo/error/notable.rb

@@ -0,0 +1,80 @@
+# Copyright (C) 2019 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
+  class Error < StandardError
+
+    # A module encapsulating note tracking functionality, since currently
+    # the driver does not have a single exception hierarchy root.
+    #
+    # @since 2.10.1
+    # @api private
+    module Notable
+
+      # Returns an array of strings with additional information about the
+      # exception.
+      #
+      # @return [ Array<String> ] Additional information strings.
+      #
+      # @since 2.10.1
+      # @api public
+      def notes
+        if @notes
+          @notes.dup
+        else
+          []
+        end
+      end
+
+      # @api private
+      def add_note(note)
+        unless @notes
+          @notes = []
+        end
+        @notes << note
+      end
+
+      # @api public
+      def message
+        super + notes_tail
+      end
+
+      # @api public
+      def to_s
+        super + notes_tail
+      end
+
+      # @api public
+      def inspect
+        msg = super
+        if msg.end_with?('>')
+          msg[0...msg.length-1] + notes_tail + '>'
+        else
+          msg + notes_tail
+        end
+      end
+
+      private
+
+      # @api private
+      def notes_tail
+        msg = ''
+        unless notes.empty?
+          msg += " (#{notes.join(', ')})"
+        end
+        msg
+      end
+    end
+  end
+end

lib/mongo/operation/shared/executable.rb

@@ -25,16 +25,18 @@ module Executable
       def do_execute(server)
         unpin_maybe(session) do
           add_error_labels do
-            get_result(server).tap do |result|
-              process_result(result, server)
+            add_server_diagnostics(server) do
+              get_result(server).tap do |result|
+                process_result(result, server)
+              end
             end
           end
         end
       end
 
       def execute(server)
         do_execute(server).tap do |result|
-          validate_result(result)
+          validate_result(result, server)
         end
       end
 

lib/mongo/operation/shared/response_handling.rb

@@ -22,10 +22,12 @@ module ResponseHandling
 
       private
 
-      def validate_result(result)
+      def validate_result(result, server)
         unpin_maybe(session) do
           add_error_labels do
-            result.validate!
+            add_server_diagnostics(server) do
+              result.validate!
+            end
           end
         end
       end
@@ -75,6 +77,18 @@ def unpin_maybe(session)
         end
         raise
       end
+
+      # Yields to the block and, if the block raises an exception, adds a note
+      # to the exception with the address of the specified server.
+      #
+      # This method is intended to add server address information to exceptions
+      # raised during execution of operations on servers.
+      def add_server_diagnostics(server)
+        yield
+      rescue Mongo::Error, Mongo::Error::AuthError => e
+        e.add_note("on #{server.address.seed}")
+        raise e
+      end
     end
   end
 end

lib/mongo/operation/shared/write.rb

@@ -41,7 +41,7 @@ def execute(server)
           else
             self.class::Command.new(spec).execute(server)
           end
-        validate_result(result)
+        validate_result(result, server)
       end
 
       # Execute the bulk write operation.

lib/mongo/retryable.rb

@@ -206,19 +206,25 @@ def write_with_retry(session, write_concern, ending_transaction = false, &block)
         return legacy_write_with_retry(server, session, &block)
       end
 
+      txn_num = if session.in_transaction?
+        session.txn_num
+      else
+        session.next_txn_num
+      end
       begin
-        txn_num = session.in_transaction? ? session.txn_num : session.next_txn_num
         yield(server, txn_num, false)
       rescue Error::SocketError, Error::SocketTimeoutError => e
+        e.add_note("attempt 1")
         if session.in_transaction? && !ending_transaction
-          raise
+          raise e
         end
         retry_write(e, session, txn_num, &block)
       rescue Error::OperationFailure => e
+        e.add_note("attempt 1")
         if e.unsupported_retryable_write?
           raise_unsupported_error(e)
         elsif (session.in_transaction? && !ending_transaction) || !e.write_retryable?
-          raise
+          raise e
         end
 
         retry_write(e, session, txn_num, &block)
@@ -274,16 +280,17 @@ def legacy_write_with_retry(server = nil, session = nil)
         server ||= select_server(cluster, ServerSelector.primary, session)
         yield server
       rescue Error::OperationFailure => e
+        e.add_note("attempt #{attempt + 1}")
         server = nil
         if attempt > client.max_write_retries
-          raise
+          raise e
         end
         if e.write_retryable? && !(session && session.in_transaction?)
           log_retry(e, message: 'Legacy write retry')
           cluster.scan!(false)
           retry
         else
-          raise
+          raise e
         end
       end
     end
@@ -296,13 +303,15 @@ def modern_read_with_retry(session, server_selector, &block)
       begin
         yield server
       rescue Error::SocketError, Error::SocketTimeoutError => e
+        e.add_note("attempt #{attempt + 1}")
         if session.in_transaction?
-          raise
+          raise e
         end
         retry_read(e, server_selector, session, &block)
       rescue Error::OperationFailure => e
+        e.add_note("attempt #{attempt + 1}")
         if session.in_transaction? || !e.write_retryable?
-          raise
+          raise e
         end
         retry_read(e, server_selector, session, &block)
       end
@@ -315,23 +324,25 @@ def legacy_read_with_retry(session, server_selector)
         attempt += 1
         yield server
       rescue Error::SocketError, Error::SocketTimeoutError => e
+        e.add_note("attempt #{attempt + 1}")
         if attempt > client.max_read_retries || (session && session.in_transaction?)
-          raise
+          raise e
         end
         log_retry(e, message: 'Legacy read retry')
         server = select_server(cluster, server_selector, session)
         retry
       rescue Error::OperationFailure => e
+        e.add_note("attempt #{attempt + 1}")
         if cluster.sharded? && e.retryable? && !(session && session.in_transaction?)
           if attempt > client.max_read_retries
-            raise
+            raise e
           end
           log_retry(e, message: 'Legacy read retry')
           sleep(client.read_retry_interval)
           server = select_server(cluster, server_selector, session)
           retry
         else
-          raise
+          raise e
         end
       end
     end
@@ -354,7 +365,8 @@ def retry_write_allowed?(session, write_concern)
     def retry_read(original_error, server_selector, session, &block)
       begin
         server = select_server(cluster, server_selector, session)
-      rescue
+      rescue => e
+        original_error.add_note("later retry failed: #{e.class}: #{e}")
         raise original_error
       end
 
@@ -363,11 +375,17 @@ def retry_read(original_error, server_selector, session, &block)
       begin
         yield server, true
       rescue Error::SocketError, Error::SocketTimeoutError => e
+        e.add_note("attempt 2")
         raise e
       rescue Error::OperationFailure => e
-        raise original_error unless e.write_retryable?
+        unless e.write_retryable?
+          original_error.add_note("later retry failed: #{e.class}: #{e}")
+          raise original_error
+        end
+        e.add_note("attempt 2")
         raise e
-      rescue
+      rescue => e
+        original_error.add_note("later retry failed: #{e.class}: #{e}")
         raise original_error
       end
     end
@@ -379,15 +397,25 @@ def retry_write(original_error, session, txn_num, &block)
       # a socket error or a not master error should have marked the respective
       # server unknown). Here we just need to wait for server selection.
       server = select_server(cluster, ServerSelector.primary, session)
-      raise original_error unless (server.retry_writes? && txn_num)
+      unless server.retry_writes?
+        original_error.add_note('did not retry because server selected for retry does not supoprt retryable writes')
+        raise original_error
+      end
       log_retry(original_error, message: 'Write retry')
       yield(server, txn_num, true)
     rescue Error::SocketError, Error::SocketTimeoutError => e
+      e.add_note('attempt 2')
       raise e
     rescue Error::OperationFailure => e
-      raise original_error unless e.write_retryable?
-      raise e
-    rescue
+      if e.write_retryable?
+        e.add_note('attempt 2')
+        raise e
+      else
+        original_error.add_note("later retry failed: #{e.class}: #{e}")
+        raise original_error
+      end
+    rescue => e
+      original_error.add_note("later retry failed: #{e.class}: #{e}")
       raise original_error
     end
 

spec/integration/change_stream_spec.rb

@@ -94,7 +94,7 @@ def clear_fail_point_before
       it 'watch raises error' do
         expect do
           authorized_collection.watch
-        end.to raise_error(Mongo::Error::OperationFailure, "Failing command due to 'failCommand' failpoint (100)")
+        end.to raise_error(Mongo::Error::OperationFailure, /Failing command due to 'failCommand' failpoint \(100\)/)
       end
     end
 
@@ -243,7 +243,7 @@ def clear_fail_point_before
 
         expect do
           enum.next
-        end.to raise_error(Mongo::Error::OperationFailure, "Failing command due to 'failCommand' failpoint (101)")
+        end.to raise_error(Mongo::Error::OperationFailure, /Failing command due to 'failCommand' failpoint \(101\)/)
       end
     end
   end
@@ -354,7 +354,7 @@ def clear_fail_point_before
 
           expect do
             enum.try_next
-          end.to raise_error(Mongo::Error::OperationFailure, "Failing command due to 'failCommand' failpoint (101)")
+          end.to raise_error(Mongo::Error::OperationFailure, /Failing command due to 'failCommand' failpoint \(101\)/)
         end
       end
 
@@ -377,7 +377,7 @@ def clear_fail_point_before
 
           expect do
             enum.try_next
-          end.to raise_error(Mongo::Error::OperationFailure, "Failing command due to 'failCommand' failpoint (101)")
+          end.to raise_error(Mongo::Error::OperationFailure, /Failing command due to 'failCommand' failpoint \(101\)/)
         end
       end
     end