diff --git a/lib/appsignal/transaction/opentelemetry_backend.rb b/lib/appsignal/transaction/opentelemetry_backend.rb index 7bed96861..b6a5551ff 100644 --- a/lib/appsignal/transaction/opentelemetry_backend.rb +++ b/lib/appsignal/transaction/opentelemetry_backend.rb @@ -281,25 +281,32 @@ def set_sample_data(key, data) # the collector to report it even on a child span; the collector computes # the digest. Causes ride on one `appsignal.error_causes` JSON attribute # (keys match the processor's `ErrorSubCause`); separate cause events would - # each become their own incident. + # each become their own incident. Each cause only carries the part of its + # backtrace that the reported error's backtrace does not already end with + # (see `trim_shared_tail`). def set_error(class_name, message, backtrace, causes, _root_cause_missing) span = current_span + error_lines = Array(backtrace) attributes = { "exception.type" => class_name, "exception.message" => message.to_s, - "exception.stacktrace" => Array(backtrace).join("\n"), + "exception.stacktrace" => error_lines.join("\n"), "appsignal.alert_this_error" => true } unless causes.empty? attributes["appsignal.error_causes"] = JSON.generate( causes.map do |cause| - { + lines, lines_omitted = trim_shared_tail(Array(cause[:backtrace]), error_lines) + + cause_attributes = { "name" => cause[:name], "message" => cause[:message], - "lines" => cause[:backtrace] || [] + "lines" => lines } + cause_attributes["lines_omitted"] = lines_omitted if lines_omitted.positive? + cause_attributes end ) end @@ -705,6 +712,41 @@ def write_tags(tags) end end + # Returns two values: the leading lines of a cause's backtrace that the + # reported error's own backtrace does not already end with, and how many + # trailing lines were dropped to get there. + # + # A cause is raised somewhere inside the frames that led to the reported + # error, so both backtraces share the same trailing frames -- everything + # from the raise point outwards, which for a web request is the whole + # framework and web server stack. Those lines are already sent once, in + # `exception.stacktrace`. Repeating them for every cause pushed the + # `appsignal.error_causes` attribute past the length the collector + # accepts, and the collector truncates an over-long attribute into + # invalid JSON, so it could not read the causes at all and dropped them. + # + # Only the trailing lines are dropped, so what is left is the part of the + # backtrace unique to the cause: where it was raised. Lines are compared + # from the end as plain strings. If every line is shared, keep the first + # one, because a cause with no lines leaves the UI nothing to show. + # + # The dropped count is returned so that the cause can report it, which + # lets the UI say how much of the backtrace is not being shown. It counts + # the lines actually removed, so when a shared line is kept it is not + # counted as dropped. + def trim_shared_tail(cause_lines, error_lines) + shared = 0 + while shared < cause_lines.length && shared < error_lines.length && + cause_lines[-1 - shared] == error_lines[-1 - shared] + shared += 1 + end + + return [cause_lines, 0] if shared.zero? + + kept = [cause_lines.length - shared, 1].max + [cause_lines.first(kept), cause_lines.length - kept] + end + # The OTel span name is what the collector surfaces as the event's # label in the trace UI. The AS::N `name` (e.g. "sql.active_record") # always leads the span name so it stays visible. When a formatter diff --git a/spec/lib/appsignal/transaction/opentelemetry_backend_spec.rb b/spec/lib/appsignal/transaction/opentelemetry_backend_spec.rb index 1952768a5..0dee2aba9 100644 --- a/spec/lib/appsignal/transaction/opentelemetry_backend_spec.rb +++ b/spec/lib/appsignal/transaction/opentelemetry_backend_spec.rb @@ -880,6 +880,171 @@ def exception_event(backend) expect(parsed).to eq([{ "name" => "ArgumentError", "message" => "bad arg", "lines" => [] }]) end + describe "a cause backtrace that shares its last lines with the error's" do + def parsed_causes(backend) + JSON.parse(exception_event(backend).attributes["appsignal.error_causes"]) + end + + def cause_lines(backend) + parsed_causes(backend).map { |cause| cause["lines"] } + end + + it "drops the trailing lines the cause shares with the error" do + backend = create_backend + causes = [ + { + :name => "ArgumentError", :message => "bad arg", + :backtrace => ["cause 1", "cause 2", "shared 1", "shared 2"] + }, + { + :name => "KeyError", :message => "missing", + :backtrace => ["cause 3", "shared 1", "shared 2"] + } + ] + backend.set_error( + "RuntimeError", "boom", ["line 1", "shared 1", "shared 2"], causes, false + ) + + expect(cause_lines(backend)).to eq([["cause 1", "cause 2"], ["cause 3"]]) + end + + it "keeps every line when the last lines differ" do + backend = create_backend + causes = [ + { + :name => "ArgumentError", :message => "bad arg", + :backtrace => ["shared 1", "shared 2", "cause 1"] + } + ] + backend.set_error( + "RuntimeError", "boom", ["shared 1", "shared 2", "line 1"], causes, false + ) + + expect(cause_lines(backend)).to eq([["shared 1", "shared 2", "cause 1"]]) + end + + it "keeps the first line when every line is shared" do + backend = create_backend + causes = [ + { + :name => "ArgumentError", :message => "bad arg", + :backtrace => ["shared 1", "shared 2"] + } + ] + backend.set_error( + "RuntimeError", "boom", ["line 1", "shared 1", "shared 2"], causes, false + ) + + expect(cause_lines(backend)).to eq([["shared 1"]]) + end + + it "keeps the first line when the cause's backtrace is the error's backtrace" do + backend = create_backend + lines = ["shared 1", "shared 2"] + causes = [{ :name => "ArgumentError", :message => "bad arg", :backtrace => lines }] + backend.set_error("RuntimeError", "boom", lines, causes, false) + + expect(cause_lines(backend)).to eq([["shared 1"]]) + end + + it "keeps every line when the error has no backtrace" do + causes = [{ :name => "ArgumentError", :message => "bad arg", :backtrace => ["cause 1"] }] + + nil_backtrace = create_backend + nil_backtrace.set_error("RuntimeError", "boom", nil, causes, false) + expect(cause_lines(nil_backtrace)).to eq([["cause 1"]]) + + empty_backtrace = create_backend + empty_backtrace.set_error("RuntimeError", "boom", [], causes, false) + expect(cause_lines(empty_backtrace)).to eq([["cause 1"]]) + end + + it "sends no lines for a cause without a backtrace" do + backend = create_backend + causes = [ + { :name => "ArgumentError", :message => "bad arg", :backtrace => nil }, + { :name => "KeyError", :message => "missing", :backtrace => [] } + ] + backend.set_error("RuntimeError", "boom", ["shared 1"], causes, false) + + expect(cause_lines(backend)).to eq([[], []]) + end + + it "reports how many lines were dropped from each cause" do + backend = create_backend + causes = [ + { + :name => "ArgumentError", :message => "bad arg", + :backtrace => ["cause 1", "cause 2", "shared 1", "shared 2"] + }, + { + :name => "KeyError", :message => "missing", + :backtrace => ["cause 3", "shared 2"] + } + ] + backend.set_error( + "RuntimeError", "boom", ["line 1", "shared 1", "shared 2"], causes, false + ) + + expect(parsed_causes(backend)).to eq( + [ + { + "name" => "ArgumentError", "message" => "bad arg", + "lines" => ["cause 1", "cause 2"], "lines_omitted" => 2 + }, + { + "name" => "KeyError", "message" => "missing", + "lines" => ["cause 3"], "lines_omitted" => 1 + } + ] + ) + end + + it "reports no dropped lines for a cause that shares no lines" do + backend = create_backend + causes = [ + { + :name => "ArgumentError", :message => "bad arg", + :backtrace => ["shared 1", "shared 2", "cause 1"] + } + ] + backend.set_error( + "RuntimeError", "boom", ["shared 1", "shared 2", "line 1"], causes, false + ) + + expect(parsed_causes(backend).first).not_to have_key("lines_omitted") + end + + # Every line is shared, but the first one is kept, so it was not dropped + # and is not counted. + it "does not count the shared line it keeps when every line is shared" do + backend = create_backend + causes = [ + { + :name => "ArgumentError", :message => "bad arg", + :backtrace => ["shared 1", "shared 2", "shared 3"] + } + ] + backend.set_error( + "RuntimeError", "boom", ["line 1", "shared 1", "shared 2", "shared 3"], causes, false + ) + + cause = parsed_causes(backend).first + expect(cause["lines"]).to eq(["shared 1"]) + expect(cause["lines_omitted"]).to eq(2) + end + + it "reports no dropped lines when the only line a cause has is shared" do + backend = create_backend + causes = [{ :name => "ArgumentError", :message => "bad arg", :backtrace => ["shared 1"] }] + backend.set_error("RuntimeError", "boom", ["line 1", "shared 1"], causes, false) + + cause = parsed_causes(backend).first + expect(cause["lines"]).to eq(["shared 1"]) + expect(cause).not_to have_key("lines_omitted") + end + end + it "does not set appsignal.error_causes when there are no causes" do backend = create_backend backend.set_error("RuntimeError", "boom", ["line 1"], [], false)