Shorten backtrace output

Get rid of duplicate lines from nested exception backtraces. We don't
need to see the same lines repated over and over in each exception.

lib/logging/layout.rb

@@ -174,9 +174,9 @@ def format_obj( obj )
   end
 
   # Internal: Format any nested exceptions found in the given exception `e`
-  # while respect the maximum `cause_depth`. The lines array is used to capture
-  # all the output lines form the nested exceptions; the array is later joined
-  # by the `format_obj` method.
+  # while respecting the maximum `cause_depth`. The lines array is used to
+  # capture all the output lines form the nested exceptions; the array is later
+  # joined by the `format_obj` method.
   #
   # e     - Exception to format
   # lines - Array of output lines
@@ -191,7 +191,7 @@ def format_cause(e, lines)
       cause = e.cause
       lines << "--- Caused by ---"
       lines << "<#{cause.class.name}> #{cause.message}"
-      lines.concat(cause.backtrace) if backtrace? && cause.backtrace
+      lines.concat(format_cause_backtrace(e, cause)) if backtrace? && cause.backtrace
 
       e = cause
     end
@@ -203,6 +203,34 @@ def format_cause(e, lines)
     lines
   end
 
+  # Internal: Format the backtrace of the nested `cause` but remove the common
+  # exception lines from the parent exception. This helps keep the backtraces a
+  # wee bit shorter and more comprehensible.
+  #
+  # e     - parent exception
+  # cause - the nested exception generating the returned backtrace
+  #
+  # Returns an Array of backtracke lines.
+  def format_cause_backtrace(e, cause)
+    # Find where the cause's backtrace differs from the parent exception's.
+    backtrace       = Array(e.backtrace)
+    cause_backtrace = Array(cause.backtrace)
+    index = -1
+    min_index = [backtrace.size, cause_backtrace.size].min * -1
+    just_in_case = -5000
+
+    while index > min_index && backtrace[index] == cause_backtrace[index] && index >= just_in_case
+      index -= 1
+    end
+
+    # Add on a few common frames to make it clear where the backtraces line up.
+    index += 3
+    index = -1 if index >= 0
+
+    cause_backtrace[0..index]
+  end
+
+
   # Attempt to format the _obj_ using yaml, but fall back to inspect style
   # formatting if yaml fails.
   #

lib/logging/layouts/parseable.rb

@@ -219,18 +219,53 @@ def items=( ary )
     def format_obj( obj )
       case obj
       when Exception
-        h = { :class   => obj.class.name,
-              :message => obj.message }
-        h[:backtrace] = obj.backtrace if backtrace? && !obj.backtrace.nil?
-        h[:cause] = format_obj(obj.cause) if defined?(obj.cause) && !obj.cause.nil?
-        h
+        hash = {
+          :class   => obj.class.name,
+          :message => obj.message
+        }
+        hash[:backtrace] = obj.backtrace if backtrace? && obj.backtrace
+
+        cause = format_cause(obj)
+        hash[:cause] = cause unless cause.empty?
+        hash
       when Time
         iso8601_format(obj)
       else
         obj
       end
     end
 
+    # Internal: Format any nested exceptions found in the given exception `e`
+    # while respecting the maximum `cause_depth`.
+    #
+    # e - Exception to format
+    #
+    # Returns the cause formatted as a Hash
+    def format_cause(e)
+      rv = curr = {}
+      prev = nil
+
+      cause_depth.times do
+        break unless e.respond_to?(:cause) && e.cause
+
+        cause = e.cause
+        curr[:class]     = cause.class.name
+        curr[:message]   = cause.message
+        curr[:backtrace] = format_cause_backtrace(e, cause) if backtrace? && cause.backtrace
+
+        prev[:cause] = curr unless prev.nil?
+        prev, curr = curr, {}
+
+        e = cause
+      end
+
+      if e.respond_to?(:cause) && e.cause
+        prev[:cause] = {message: "Further #cause backtraces were omitted"}
+      end
+
+      rv
+    end
+
   private
 
     # Call the appropriate class level create format method based on the
@@ -258,6 +293,5 @@ def iso8601_format( time )
       return str << (value.gmt_offset < 0 ? '-' : '+') << offset
     end
 
-  end  # Parseable
-end  # Logging::Layouts
-
+  end
+end

test/layouts/test_nested_exceptions.rb

@@ -59,31 +59,66 @@ def test_parseable_format_obj
         err = nil
         begin
           begin
-            raise StandardError, 'nested exception'
+            raise ArgumentError, 'nested exception'
           rescue
-            raise Exception, 'root exception'
+            raise StandardError, 'root exception'
           end
-        rescue Object => e
+        rescue => e
           err = e
         end
 
         layout = Logging.layouts.parseable.new
         log = layout.format_obj(e)
-        assert_equal Exception.name, log[:class]
+        assert_equal 'StandardError', log[:class]
         assert_equal 'root exception', log[:message]
-        assert_operator log[:backtrace].size, :>, 0
+        assert log[:backtrace].size > 0
 
-        if defined? e.cause
+        if e.respond_to?(:cause)
           assert_not_nil log[:cause]
 
           log = log[:cause]
-          assert_equal StandardError.name, log[:class]
+          assert_equal 'ArgumentError', log[:class]
           assert_equal 'nested exception', log[:message]
           assert_nil log[:cause]
-          assert_operator log[:backtrace].size, :>, 0
+          assert log[:backtrace].size > 0
+        end
+      end
+
+      def test_parseable_cause_depth_limiting
+        err = nil
+        begin
+          begin
+            begin
+              raise TypeError, 'nested exception 2'
+            rescue
+              raise ArgumentError, 'nested exception 1'
+            end
+          rescue
+            raise StandardError, 'root exception'
+          end
+        rescue => e
+          err = e
+        end
+
+        layout = Logging.layouts.parseable.new(cause_depth: 1)
+        log = layout.format_obj(e)
+
+        assert_equal 'StandardError', log[:class]
+        assert_equal 'root exception', log[:message]
+        assert log[:backtrace].size > 0
+
+        if e.respond_to?(:cause)
+          assert_not_nil log[:cause]
+
+          log = log[:cause]
+          assert_equal 'ArgumentError', log[:class]
+          assert_equal 'nested exception 1', log[:message]
+          assert_equal({message: "Further #cause backtraces were omitted"}, log[:cause])
+          assert log[:backtrace].size > 0
         end
       end
     end
   end
 end
 
+require 'pp'