From 496b035a3510dbb6dc47c7c59172f488ec55c986 Mon Sep 17 00:00:00 2001 From: Tom de Bruijn Date: Mon, 23 Sep 2024 15:20:17 +0200 Subject: [PATCH 1/2] Add first backtrace line to error causes To give a bit more context about the error causes, include the first backtrace line, showing where it originates. The server needs to be updated to show this in the UI. Part of https://github.com/appsignal/feature-requests/issues/387 --- ...-first-backtrace-line-from-error-causes.md | 6 + lib/appsignal/transaction.rb | 24 +++- spec/lib/appsignal/transaction_spec.rb | 121 +++++++++++++++++- 3 files changed, 145 insertions(+), 6 deletions(-) create mode 100644 .changesets/include-first-backtrace-line-from-error-causes.md diff --git a/.changesets/include-first-backtrace-line-from-error-causes.md b/.changesets/include-first-backtrace-line-from-error-causes.md new file mode 100644 index 000000000..190be7915 --- /dev/null +++ b/.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. diff --git a/lib/appsignal/transaction.rb b/lib/appsignal/transaction.rb index 3105928fa..0706319d3 100644 --- a/lib/appsignal/transaction.rb +++ b/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,27 @@ def _set_error(error) ) end + BACKTRACE_REGEX = + %r{(?[\w-]+ \(.+\) )?(?:?/?\w+?.+?):(?:?\d+)(?:in `(?.+)')?$}.freeze # rubocop:disable Layout/LineLength + + def first_formatted_backtrace_line(error) + first_line = error.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| + c.delete("group") # Unused key, only for easier matching + # Strip of whitespace at the end of the gem name + c["gem"] = c["gem"]&.strip + # Add revision for linking to the repository from the UI + c["revision"] = Appsignal.config[:revision] + end + end + def set_sample_data(key, data) return unless key && data diff --git a/spec/lib/appsignal/transaction_spec.rb b/spec/lib/appsignal/transaction_spec.rb index 94260295f..d3c0e0f56 100644 --- a/spec/lib/appsignal/transaction_spec.rb +++ b/spec/lib/appsignal/transaction_spec.rb @@ -1838,17 +1838,38 @@ 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 transaction.send(:_set_error, error) @@ -1856,17 +1877,42 @@ def to_s 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" + "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 3", + "first_line" => nil } ] ) @@ -1884,6 +1930,70 @@ def to_s expect(transaction).to include_error_causes([]) 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 +2014,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 From 097bc32373bb796a258bc47769f69f46d3492507 Mon Sep 17 00:00:00 2001 From: Tom de Bruijn Date: Wed, 25 Sep 2024 11:05:28 +0200 Subject: [PATCH 2/2] Run error cause backtrace lines through filters If the Rails backtrace cleaner filter is present also run the error cause backtrace through the filter as well. Replicate our processor behavior for the error causes by stripping of the app/root path in the Ruby gem. --- lib/appsignal/transaction.rb | 13 +++- spec/lib/appsignal/transaction_spec.rb | 88 +++++++++++++++++++++++++- spec/support/helpers/config_helpers.rb | 9 ++- 3 files changed, 104 insertions(+), 6 deletions(-) diff --git a/lib/appsignal/transaction.rb b/lib/appsignal/transaction.rb index 0706319d3..7a14697c0 100644 --- a/lib/appsignal/transaction.rb +++ b/lib/appsignal/transaction.rb @@ -644,7 +644,8 @@ def _set_error(error) %r{(?[\w-]+ \(.+\) )?(?:?/?\w+?.+?):(?:?\d+)(?:in `(?.+)')?$}.freeze # rubocop:disable Layout/LineLength def first_formatted_backtrace_line(error) - first_line = error.backtrace&.first + backtrace = cleaned_backtrace(error.backtrace) + first_line = backtrace&.first return unless first_line captures = BACKTRACE_REGEX.match(first_line) @@ -653,11 +654,19 @@ def first_formatted_backtrace_line(error) 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"] = Appsignal.config[:revision] + c["revision"] = config[:revision] end end diff --git a/spec/lib/appsignal/transaction_spec.rb b/spec/lib/appsignal/transaction_spec.rb index d3c0e0f56..a774bd223 100644 --- a/spec/lib/appsignal/transaction_spec.rb +++ b/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 } @@ -1865,13 +1866,16 @@ def to_s 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( @@ -1931,6 +1935,86 @@ 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") diff --git a/spec/support/helpers/config_helpers.rb b/spec/support/helpers/config_helpers.rb index 3afb43d13..e92b360ec 100644 --- a/spec/support/helpers/config_helpers.rb +++ b/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