Skip to content

Commit

Permalink
Add client reports for span drop counts
Browse files Browse the repository at this point in the history
  • Loading branch information
sl0thentr0py committed Jul 23, 2024
1 parent c16a0f2 commit 73a27e1
Show file tree
Hide file tree
Showing 10 changed files with 122 additions and 25 deletions.
3 changes: 2 additions & 1 deletion CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,8 @@

### Internal

- Use Concurrent.usable_processor_count when it is available ([#2339](https://github.com/getsentry/sentry-ruby/pull/2339))
- Use `Concurrent.usable_processor_count` when it is available ([#2339](https://github.com/getsentry/sentry-ruby/pull/2339))
- Report dropped spans in Client Reports ([#2346](https://github.com/getsentry/sentry-ruby/pull/2346))

### Bug Fixes

Expand Down
23 changes: 20 additions & 3 deletions sentry-ruby/lib/sentry/client.rb
Original file line number Diff line number Diff line change
Expand Up @@ -55,19 +55,29 @@ def capture_event(event, scope, hint = {})

event_type = event.is_a?(Event) ? event.type : event["type"]
data_category = Envelope::Item.data_category(event_type)

is_transaction = event.is_a?(TransactionEvent)
spans_before = is_transaction ? event.spans.size : 0

event = scope.apply_to_event(event, hint)

if event.nil?
log_debug("Discarded event because one of the event processors returned nil")
transport.record_lost_event(:event_processor, data_category)
transport.record_lost_event(:event_processor, 'span', num: spans_before + 1) if is_transaction
return
elsif is_transaction
spans_delta = spans_before - event.spans.size
transport.record_lost_event(:event_processor, 'span', num: spans_delta) if spans_delta > 0
end

if async_block = configuration.async
dispatch_async_event(async_block, event, hint)
elsif configuration.background_worker_threads != 0 && hint.fetch(:background, true)
queued = dispatch_background_event(event, hint)
transport.record_lost_event(:queue_overflow, data_category) unless queued
unless dispatch_background_event(event, hint)
transport.record_lost_event(:queue_overflow, data_category)
transport.record_lost_event(:queue_overflow, 'span', num: spans_before + 1) if is_transaction
end
else
send_event(event, hint)
end
Expand Down Expand Up @@ -168,6 +178,7 @@ def event_from_transaction(transaction)
def send_event(event, hint = nil)
event_type = event.is_a?(Event) ? event.type : event["type"]
data_category = Envelope::Item.data_category(event_type)
spans_before = event.is_a?(TransactionEvent) ? event.spans.size : 0

if event_type != TransactionEvent::TYPE && configuration.before_send
event = configuration.before_send.call(event, hint)
Expand All @@ -184,8 +195,13 @@ def send_event(event, hint = nil)

if event.nil?
log_debug("Discarded event because before_send_transaction returned nil")
transport.record_lost_event(:before_send, data_category)
transport.record_lost_event(:before_send, 'transaction')
transport.record_lost_event(:before_send, 'span', num: spans_before + 1)
return
else
spans_after = event.is_a?(TransactionEvent) ? event.spans.size : 0
spans_delta = spans_before - spans_after
transport.record_lost_event(:before_send, 'span', num: spans_delta) if spans_delta > 0
end
end

Expand All @@ -196,6 +212,7 @@ def send_event(event, hint = nil)
rescue => e
log_error("Event sending failed", e, debug: configuration.debug)
transport.record_lost_event(:network_error, data_category)
transport.record_lost_event(:network_error, 'span', num: spans_before + 1) if event.is_a?(TransactionEvent)
raise
end

Expand Down
2 changes: 1 addition & 1 deletion sentry-ruby/lib/sentry/envelope.rb
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,7 @@ def type
# rate limits and client reports use the data_category rather than envelope item type
def self.data_category(type)
case type
when 'session', 'attachment', 'transaction', 'profile' then type
when 'session', 'attachment', 'transaction', 'profile', 'span' then type
when 'sessions' then 'session'
when 'check_in' then 'monitor'
when 'statsd', 'metric_meta' then 'metric_bucket'
Expand Down
1 change: 1 addition & 0 deletions sentry-ruby/lib/sentry/transaction.rb
Original file line number Diff line number Diff line change
Expand Up @@ -266,6 +266,7 @@ def finish(hub: nil, end_timestamp: nil)
is_backpressure = Sentry.backpressure_monitor&.downsample_factor&.positive?
reason = is_backpressure ? :backpressure : :sample_rate
hub.current_client.transport.record_lost_event(reason, 'transaction')
hub.current_client.transport.record_lost_event(reason, 'span')
end
end

Expand Down
4 changes: 2 additions & 2 deletions sentry-ruby/lib/sentry/transport.rb
Original file line number Diff line number Diff line change
Expand Up @@ -151,11 +151,11 @@ def envelope_from_event(event)
envelope
end

def record_lost_event(reason, data_category)
def record_lost_event(reason, data_category, num: 1)
return unless @send_client_reports
return unless CLIENT_REPORT_REASONS.include?(reason)

@discarded_events[[reason, data_category]] += 1
@discarded_events[[reason, data_category]] += num
end

def flush
Expand Down
103 changes: 88 additions & 15 deletions sentry-ruby/spec/sentry/client/event_sending_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,13 @@
Sentry::Hub.new(subject, Sentry::Scope.new)
end

let(:transaction) do
transaction = Sentry::Transaction.new(name: "test transaction", op: "rack.request", hub: hub)
5.times { |i| transaction.with_child_span(description: "span_#{i}") { } }
transaction
end
let(:transaction_event) { subject.event_from_transaction(transaction) }

describe "#capture_event" do
let(:message) { "Test message" }
let(:scope) { Sentry::Scope.new }
Expand Down Expand Up @@ -42,11 +49,8 @@

context "with TransactionEvent" do
it "ignores the sampling" do
transaction_event = subject.event_from_transaction(Sentry::Transaction.new(hub: hub))
allow(Random).to receive(:rand).and_return(0.51)

subject.capture_event(transaction_event, scope)

expect(subject.transport.events.count).to eq(1)
end
end
Expand Down Expand Up @@ -167,7 +171,7 @@
end
end

it "records queue overflow" do
it "records queue overflow for error event" do
allow(Sentry.background_worker).to receive(:perform).and_return(false)

subject.capture_event(event, scope)
Expand All @@ -177,16 +181,25 @@
sleep(0.2)
expect(subject.transport.events.count).to eq(0)
end

it "records queue overflow for transaction event with span counts" do
allow(Sentry.background_worker).to receive(:perform).and_return(false)

subject.capture_event(transaction_event, scope)
expect(subject.transport).to have_recorded_lost_event(:queue_overflow, 'transaction')
expect(subject.transport).to have_recorded_lost_event(:queue_overflow, 'span', num: 6)

expect(subject.transport.events.count).to eq(0)
sleep(0.2)
expect(subject.transport.events.count).to eq(0)
end
end
end

describe "#send_event" do
let(:event_object) do
subject.event_from_exception(ZeroDivisionError.new("divided by 0"))
end
let(:transaction_event_object) do
subject.event_from_transaction(Sentry::Transaction.new(hub: hub))
end

shared_examples "Event in send_event" do
context "when there's an exception" do
Expand Down Expand Up @@ -278,11 +291,11 @@
end

it_behaves_like "TransactionEvent in send_event" do
let(:event) { transaction_event_object }
let(:event) { transaction_event }
end

it_behaves_like "TransactionEvent in send_event" do
let(:event) { transaction_event_object.to_json_compatible }
let(:event) { transaction_event.to_json_compatible }
end
end

Expand Down Expand Up @@ -319,9 +332,33 @@
it "discards the event and logs a info" do
expect(subject.capture_event(event, scope)).to be_nil

expect(subject.transport).to have_recorded_lost_event(:event_processor, 'error')
expect(string_io.string).to match(/Discarded event because one of the event processors returned nil/)
end

it "records correct client report for error event" do
subject.capture_event(event, scope)
expect(subject.transport).to have_recorded_lost_event(:event_processor, 'error')
end

it "records correct transaction and span client reports for transaction event" do
subject.capture_event(transaction_event, scope)
expect(subject.transport).to have_recorded_lost_event(:event_processor, 'transaction')
expect(subject.transport).to have_recorded_lost_event(:event_processor, 'span', num: 6)
end
end

context "when scope.apply_to_event modifies spans" do
before do
scope.add_event_processor do |event, hint|
2.times { event.spans.pop }
event
end
end

it "records correct span delta client report for transaction event" do
subject.capture_event(transaction_event, scope)
expect(subject.transport).to have_recorded_lost_event(:event_processor, 'span', num: 2)
end
end

context "when scope.apply_to_event fails" do
Expand Down Expand Up @@ -360,7 +397,6 @@
it "swallows and logs Sentry::ExternalError (caused by transport's networking error)" do
expect(subject.capture_event(event, scope)).to be_nil

expect(subject.transport).to have_recorded_lost_event(:network_error, 'error')
expect(string_io.string).to match(/Event sending failed: Failed to open TCP connection/)
expect(string_io.string).to match(/Event capturing failed: Failed to open TCP connection/)
end
Expand All @@ -372,6 +408,17 @@

expect(string_io.string).to match(/Event sending failed: TypeError/)
end

it "captures client report for error event" do
subject.capture_event(event, scope)
expect(subject.transport).to have_recorded_lost_event(:network_error, 'error')
end

it "captures client report for transaction event with span counts" do
subject.capture_event(transaction_event, scope)
expect(subject.transport).to have_recorded_lost_event(:network_error, 'transaction')
expect(subject.transport).to have_recorded_lost_event(:network_error, 'span', num: 6)
end
end

context "when sending events in background causes error", retry: 3 do
Expand All @@ -383,7 +430,6 @@
expect(subject.capture_event(event, scope)).to be_a(Sentry::ErrorEvent)
sleep(0.2)

expect(subject.transport).to have_recorded_lost_event(:network_error, 'error')
expect(string_io.string).to match(/Event sending failed: Failed to open TCP connection/)
end

Expand All @@ -395,6 +441,19 @@

expect(string_io.string).to match(/Event sending failed: TypeError/)
end

it "captures client report for error event" do
subject.capture_event(event, scope)
sleep(0.2)
expect(subject.transport).to have_recorded_lost_event(:network_error, 'error')
end

it "captures client report for transaction event with span counts" do
subject.capture_event(transaction_event, scope)
sleep(0.2)
expect(subject.transport).to have_recorded_lost_event(:network_error, 'transaction')
expect(subject.transport).to have_recorded_lost_event(:network_error, 'span', num: 6)
end
end

context "when config.async causes error" do
Expand Down Expand Up @@ -469,7 +528,7 @@
end
end

it "records lost event" do
it "records lost error event" do
subject.send_event(event)
expect(subject.transport).to have_recorded_lost_event(:before_send, 'error')
end
Expand All @@ -482,10 +541,24 @@
end
end

it "records lost event" do
transaction_event = subject.event_from_transaction(Sentry::Transaction.new(hub: hub))
it "records lost transaction with span counts client reports" do
subject.send_event(transaction_event)
expect(subject.transport).to have_recorded_lost_event(:before_send, 'transaction')
expect(subject.transport).to have_recorded_lost_event(:before_send, 'span', num: 6)
end
end

context "before_send_transaction modifies spans" do
before do
configuration.before_send_transaction = lambda do |event, _hint|
2.times { event.spans.pop }
event
end
end

it "records lost span delta client reports" do
expect { subject.send_event(transaction_event) }.to raise_error(Sentry::ExternalError)
expect(subject.transport).to have_recorded_lost_event(:before_send, 'span', num: 2)
end
end
end
Expand Down
1 change: 1 addition & 0 deletions sentry-ruby/spec/sentry/envelope_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
['sessions', 'session'],
['attachment', 'attachment'],
['transaction', 'transaction'],
['span', 'span'],
['profile', 'profile'],
['check_in', 'monitor'],
['statsd', 'metric_bucket'],
Expand Down
2 changes: 2 additions & 0 deletions sentry-ruby/spec/sentry/transaction_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -494,6 +494,7 @@
it "records lost event with reason sample_rate" do
subject.finish
expect(Sentry.get_current_client.transport).to have_recorded_lost_event(:sample_rate, 'transaction')
expect(Sentry.get_current_client.transport).to have_recorded_lost_event(:sample_rate, 'span')
end
end

Expand All @@ -514,6 +515,7 @@

subject.finish
expect(Sentry.get_current_client.transport).to have_recorded_lost_event(:backpressure, 'transaction')
expect(Sentry.get_current_client.transport).to have_recorded_lost_event(:backpressure, 'span')
end
end

Expand Down
4 changes: 3 additions & 1 deletion sentry-ruby/spec/sentry/transport_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -153,6 +153,7 @@
before do
5.times { subject.record_lost_event(:ratelimit_backoff, 'error') }
3.times { subject.record_lost_event(:queue_overflow, 'transaction') }
2.times { subject.record_lost_event(:network_error, 'span', num: 5) }
end

it "incudes client report in envelope" do
Expand All @@ -170,7 +171,8 @@
timestamp: Time.now.utc.iso8601,
discarded_events: [
{ reason: :ratelimit_backoff, category: 'error', quantity: 5 },
{ reason: :queue_overflow, category: 'transaction', quantity: 3 }
{ reason: :queue_overflow, category: 'transaction', quantity: 3 },
{ reason: :network_error, category: 'span', quantity: 10 }
]
}.to_json
)
Expand Down
4 changes: 2 additions & 2 deletions sentry-ruby/spec/spec_helper.rb
Original file line number Diff line number Diff line change
Expand Up @@ -50,9 +50,9 @@
skip("skip rack related tests") unless defined?(Rack)
end

RSpec::Matchers.define :have_recorded_lost_event do |reason, data_category|
RSpec::Matchers.define :have_recorded_lost_event do |reason, data_category, num: 1|
match do |transport|
expect(transport.discarded_events[[reason, data_category]]).to be > 0
expect(transport.discarded_events[[reason, data_category]]).to eq(num)
end
end
end
Expand Down

0 comments on commit 73a27e1

Please sign in to comment.