Merge pull request #1304 from appsignal/cause-line

Add first backtrace line to error causes

.changesets/include-first-backtrace-line-from-error-causes.md

@@ -0,0 +1,6 @@
+---
+bump: patch
+type: add
+---
+
+Include the first backtrace line from error causes to show where each cause originated in the interface.

lib/appsignal/transaction.rb

@@ -627,7 +627,8 @@ def _set_error(error)
       causes_sample_data = causes.map do |e|
         {
           :name => e.class.name,
-          :message => cleaned_error_message(e)
+          :message => cleaned_error_message(e),
+          :first_line => first_formatted_backtrace_line(e)
         }
       end
 
@@ -639,6 +640,36 @@ def _set_error(error)
       )
     end
 
+    BACKTRACE_REGEX =
+      %r{(?<gem>[\w-]+ \(.+\) )?(?<path>:?/?\w+?.+?):(?<line>:?\d+)(?<group>:in `(?<method>.+)')?$}.freeze # rubocop:disable Layout/LineLength
+
+    def first_formatted_backtrace_line(error)
+      backtrace = cleaned_backtrace(error.backtrace)
+      first_line = backtrace&.first
+      return unless first_line
+
+      captures = BACKTRACE_REGEX.match(first_line)
+      return unless captures
+
+      captures.named_captures
+        .merge("original" => first_line)
+        .tap do |c|
+          config = Appsignal.config
+          c.delete("group") # Unused key, only for easier matching
+          # Strip of whitespace at the end of the gem name
+          c["gem"] = c["gem"]&.strip
+          # Strip the app path from the path if present
+          root_path = config.root_path
+          if c["path"].start_with?(root_path)
+            c["path"].delete_prefix!(root_path)
+            # Relative paths shouldn't start with a slash
+            c["path"].delete_prefix!("/")
+          end
+          # Add revision for linking to the repository from the UI
+          c["revision"] = config[:revision]
+        end
+    end
+
     def set_sample_data(key, data)
       return unless key && data
 

spec/lib/appsignal/transaction_spec.rb

@@ -1,9 +1,10 @@
 describe Appsignal::Transaction do
   let(:options) { {} }
   let(:time) { Time.at(fixed_time) }
+  let(:root_path) { nil }
 
   before do
-    start_agent(:options => options)
+    start_agent(:options => options, :root_path => root_path)
     Timecop.freeze(time)
   end
   after { Timecop.return }
@@ -1838,35 +1839,84 @@ def to_s
     context "when the error has multiple causes" do
       let(:error) do
         e = ExampleStandardError.new("test message")
-        e.set_backtrace(["line 1"])
+        e.set_backtrace([
+          "/absolute/path/example.rb:9123:in `my_method'",
+          "/absolute/path/context.rb:9456:in `context_method'",
+          "/absolute/path/suite.rb:9789:in `suite_method'"
+        ])
         e2 = RuntimeError.new("cause message")
+        e2.set_backtrace([
+          # Absolute path with gem name
+          "my_gem (1.2.3) /absolute/path/example.rb:123:in `my_method'",
+          "other_gem (4.5.6) /absolute/path/context.rb:456:in `context_method'",
+          "other_gem (4.5.6) /absolute/path/suite.rb:789:in `suite_method'"
+        ])
         e3 = StandardError.new("cause message 2")
+        e3.set_backtrace([
+          # Relative paths
+          "src/example.rb:123:in `my_method'",
+          "context.rb:456:in `context_method'",
+          "suite.rb:789:in `suite_method'"
+        ])
+        e4 = StandardError.new("cause message 3")
+        e4.set_backtrace([]) # No backtrace
+
         allow(e).to receive(:cause).and_return(e2)
         allow(e2).to receive(:cause).and_return(e3)
+        allow(e3).to receive(:cause).and_return(e4)
         e
       end
-
       let(:error_without_cause) do
         ExampleStandardError.new("error without cause")
       end
+      let(:options) { { :revision => "my_revision" } }
 
       it "sends the causes information as sample data" do
+        # Hide Rails so we can test the normal Ruby behavior. The Rails
+        # behavior is tested in another spec.
+        hide_const("Rails")
+
         transaction.send(:_set_error, error)
 
         expect(transaction).to have_error(
           "ExampleStandardError",
           "test message",
-          ["line 1"]
+          [
+            "/absolute/path/example.rb:9123:in `my_method'",
+            "/absolute/path/context.rb:9456:in `context_method'",
+            "/absolute/path/suite.rb:9789:in `suite_method'"
+          ]
         )
         expect(transaction).to include_error_causes(
           [
             {
               "name" => "RuntimeError",
-              "message" => "cause message"
+              "message" => "cause message",
+              "first_line" => {
+                "original" => "my_gem (1.2.3) /absolute/path/example.rb:123:in `my_method'",
+                "gem" => "my_gem (1.2.3)",
+                "path" => "/absolute/path/example.rb",
+                "line" => "123",
+                "method" => "my_method",
+                "revision" => "my_revision"
+              }
+            },
+            {
+              "name" => "StandardError",
+              "message" => "cause message 2",
+              "first_line" => {
+                "original" => "src/example.rb:123:in `my_method'",
+                "gem" => nil,
+                "path" => "src/example.rb",
+                "line" => "123",
+                "method" => "my_method",
+                "revision" => "my_revision"
+              }
             },
             {
               "name" => "StandardError",
-              "message" => "cause message 2"
+              "message" => "cause message 3",
+              "first_line" => nil
             }
           ]
         )
@@ -1884,6 +1934,150 @@ def to_s
 
         expect(transaction).to include_error_causes([])
       end
+
+      describe "with app paths" do
+        let(:root_path) { project_fixture_path }
+        let(:error) do
+          e = ExampleStandardError.new("test message")
+          e2 = RuntimeError.new("cause message")
+          e2.set_backtrace(["#{root_path}/src/example.rb:123:in `my_method'"])
+          allow(e).to receive(:cause).and_return(e2)
+          e
+        end
+
+        it "sends the causes information as sample data" do
+          # Hide Rails so we can test the normal Ruby behavior. The Rails
+          # behavior is tested in another spec.
+          hide_const("Rails")
+
+          transaction.send(:_set_error, error)
+
+          path = "src/example.rb"
+          original_path = "#{root_path}/#{path}"
+
+          expect(transaction).to include_error_causes([
+            {
+              "name" => "RuntimeError",
+              "message" => "cause message",
+              "first_line" => {
+                "original" => "#{original_path}:123:in `my_method'",
+                "gem" => nil,
+                "path" => path,
+                "line" => "123",
+                "method" => "my_method",
+                "revision" => "my_revision"
+              }
+            }
+          ])
+        end
+      end
+
+      if rails_present?
+        describe "with Rails" do
+          let(:root_path) { project_fixture_path }
+          let(:error) do
+            e = ExampleStandardError.new("test message")
+            e2 = RuntimeError.new("cause message")
+            e2.set_backtrace([
+              "#{root_path}/src/example.rb:123:in `my_method'"
+            ])
+            allow(e).to receive(:cause).and_return(e2)
+            e
+          end
+
+          it "sends the causes information as sample data" do
+            transaction.send(:_set_error, error)
+
+            path = "src/example.rb"
+            original_path = "#{root_path}/#{path}"
+            # When Rails is present we run it through the Rails backtrace cleaner
+            # that removes the app path from the backtrace lines, so update our
+            # assertion to match.
+            original_path.delete_prefix!(DirectoryHelper.project_dir)
+            original_path.delete_prefix!("/")
+            path = original_path
+
+            expect(transaction).to include_error_causes([
+              {
+                "name" => "RuntimeError",
+                "message" => "cause message",
+                "first_line" => {
+                  "original" => "#{original_path}:123:in `my_method'",
+                  "gem" => nil,
+                  "path" => path,
+                  "line" => "123",
+                  "method" => "my_method",
+                  "revision" => "my_revision"
+                }
+              }
+            ])
+          end
+        end
+      end
+
+      describe "HAML backtrace lines" do
+        let(:error) do
+          e = ExampleStandardError.new("test message")
+          e2 = RuntimeError.new("cause message")
+          e2.set_backtrace([
+            "app/views/search/_navigation_tabs.html.haml:17"
+          ])
+          allow(e).to receive(:cause).and_return(e2)
+          e
+        end
+
+        it "sends the causes information as sample data" do
+          transaction.send(:_set_error, error)
+
+          expect(transaction).to include_error_causes(
+            [
+              {
+                "name" => "RuntimeError",
+                "message" => "cause message",
+                "first_line" => {
+                  "original" => "app/views/search/_navigation_tabs.html.haml:17",
+                  "gem" => nil,
+                  "path" => "app/views/search/_navigation_tabs.html.haml",
+                  "line" => "17",
+                  "method" => nil,
+                  "revision" => "my_revision"
+                }
+              }
+            ]
+          )
+        end
+      end
+
+      describe "invalid backtrace lines" do
+        let(:error) do
+          e = ExampleStandardError.new("test message")
+          e.set_backtrace([
+            "/absolute/path/example.rb:9123:in `my_method'",
+            "/absolute/path/context.rb:9456:in `context_method'",
+            "/absolute/path/suite.rb:9789:in `suite_method'"
+          ])
+          e2 = RuntimeError.new("cause message")
+          e2.set_backtrace([
+            "(lorem) abc def xyz.123 `function yes '"
+          ])
+          allow(e).to receive(:cause).and_return(e2)
+          e
+        end
+
+        it "doesn't send the cause line information as sample data" do
+          transaction.send(:_set_error, error)
+
+          expect(transaction).to include_error_causes(
+            [
+              {
+                "name" => "RuntimeError",
+                "message" => "cause message",
+                "first_line" => nil
+              }
+            ]
+          )
+        end
+      end
     end
 
     context "when the error has too many causes" do
@@ -1904,7 +2098,8 @@ def to_s
           Array.new(10) do |i|
             {
               "name" => "ExampleStandardError",
-              "message" => "wrapper error #{9 - i}"
+              "message" => "wrapper error #{9 - i}",
+              "first_line" => nil
             }
           end
         expected_error_causes.last["is_root_cause"] = false

spec/support/helpers/config_helpers.rb

@@ -46,10 +46,15 @@ def build_config(
   end
   module_function :build_config
 
-  def start_agent(env: "production", options: {}, internal_logger: nil)
+  def start_agent(
+    env: "production",
+    root_path: nil,
+    options: {},
+    internal_logger: nil
+  )
     env = "production" if env == :default
     env ||= "production"
-    Appsignal.configure(env, :root_path => project_fixture_path) do |config|
+    Appsignal.configure(env, :root_path => root_path || project_fixture_path) do |config|
       options.each do |option, value|
         config.send("#{option}=", value)
       end