Merge pull request rails#50305 from MaxLap/log_cause_trace_debug_exceptions

Log trace of causes for unhandled exceptions

Author: rafaelfranca

actionpack/lib/action_dispatch/middleware/debug_exceptions.rb

@@ -142,17 +142,30 @@ def log_error(request, wrapper)
 
         message = []
         message << "  "
-        message << "#{wrapper.exception_class_name} (#{wrapper.message}):"
         if wrapper.has_cause?
-          message << "\nCauses:"
+          message << "#{wrapper.exception_class_name} (#{wrapper.message})"
           wrapper.wrapped_causes.each do |wrapped_cause|
-            message << "#{wrapped_cause.exception_class_name} (#{wrapped_cause.message})"
+            message << "Caused by: #{wrapped_cause.exception_class_name} (#{wrapped_cause.message})"
           end
+
+          message << "\nInformation for: #{wrapper.exception_class_name} (#{wrapper.message}):"
+        else
+          message << "#{wrapper.exception_class_name} (#{wrapper.message}):"
         end
+
         message.concat(wrapper.annotated_source_code)
         message << "  "
         message.concat(trace)
 
+        if wrapper.has_cause?
+          wrapper.wrapped_causes.each do |wrapped_cause|
+            message << "\nInformation for cause: #{wrapped_cause.exception_class_name} (#{wrapped_cause.message}):"
+            message.concat(wrapped_cause.annotated_source_code)
+            message << "  "
+            message.concat(wrapped_cause.exception_trace)
+          end
+        end
+
         log_array(logger, message, request)
       end
 

actionpack/test/dispatch/debug_exceptions_test.rb

@@ -627,11 +627,43 @@ def self.build_app(app, *args)
     get "/nested_exceptions", headers: env
     assert_response 500
     log = output.rewind && output.read
-    assert_includes log, <<~MSG
-      Causes:
-      RuntimeError (Second error)
-      RuntimeError (First error)
+
+    # Splitting into paragraphs to be easier to see difference/error when there is one
+    paragraphs = log.split(/\n\s*\n/)
+
+    assert_includes(paragraphs[0], <<~MSG.strip)
+      RuntimeError (Third error)
+      Caused by: RuntimeError (Second error)
+      Caused by: RuntimeError (First error)
+    MSG
+
+    assert_includes(paragraphs[1], <<~MSG.strip)
+      Information for: RuntimeError (Third error):
+    MSG
+
+    assert_match Regexp.new(<<~REGEX.strip), paragraphs[2].lines[0..2].join
+      \\A.*in `rescue in rescue in raise_nested_exceptions'
+      .*in `rescue in raise_nested_exceptions'
+      .*in `raise_nested_exceptions'
+    REGEX
+
+    assert_includes(paragraphs[3], <<~MSG.strip)
+      Information for cause: RuntimeError (Second error):
+    MSG
+
+    assert_match Regexp.new(<<~REGEX.strip), paragraphs[4].lines[0..1].join
+      \\A.*in `rescue in raise_nested_exceptions'
+      .*in `raise_nested_exceptions'
+    REGEX
+
+
+    assert_includes(paragraphs[5], <<~MSG.strip)
+      Information for cause: RuntimeError (First error):
     MSG
+
+    assert_match Regexp.new(<<~REGEX.strip), paragraphs[6].lines[0]
+      \\A.*in `raise_nested_exceptions'
+    REGEX
   end
 
   test "display backtrace when error type is SyntaxError" do