Log message when events are not sent due to rate limiting

Author: st0012

sentry-ruby/lib/sentry/transport.rb

@@ -7,6 +7,7 @@ class Transport
     USER_AGENT = "sentry-ruby/#{Sentry::VERSION}"
 
     attr_accessor :configuration
+    attr_reader :rate_limits
 
     def initialize(configuration)
       @configuration = configuration
@@ -20,12 +21,24 @@ def send_data(data, options = {})
     end
 
     def send_event(event)
+      event_hash = event.to_hash
+      item_type = get_item_type(event_hash)
+
       unless configuration.sending_allowed?
-        configuration.logger.debug(LOGGER_PROGNAME) { "Event not sent: #{configuration.error_messages}" }
+        configuration.logger.debug(LOGGER_PROGNAME) do
+          "Envelope [#{item_type}] not sent: #{configuration.error_messages}"
+        end
+
         return
       end
 
-      return if is_rate_limited?(event)
+      if is_rate_limited?(item_type)
+        configuration.logger.info(LOGGER_PROGNAME) do
+          "Envelope [#{item_type}] not sent: rate limiting"
+        end
+
+        return
+      end
 
       encoded_data = encode(event)
 
@@ -36,18 +49,14 @@ def send_event(event)
       event
     end
 
-    def is_rate_limited?(event)
-      event_hash = event.to_hash
-      event_type = event_hash[:type] || event_hash['type']
-
+    def is_rate_limited?(item_type)
       # check category-specific limit
       delay =
-        case event_type
-        when "event"
-          # confusing mapping, but it's decided by Sentry
-          @rate_limits["error"]
+        case item_type
         when "transaction"
           @rate_limits["transaction"]
+        else
+          @rate_limits["error"]
         end
 
       # check universal limit if not category limit
@@ -73,7 +82,7 @@ def encode(event)
       event_hash = event.to_hash
 
       event_id = event_hash[:event_id] || event_hash["event_id"]
-      item_type = event_hash[:type] || event_hash["type"] || "event"
+      item_type = get_item_type(event_hash)
 
       envelope = <<~ENVELOPE
         {"event_id":"#{event_id}","dsn":"#{configuration.dsn.to_s}","sdk":#{Sentry.sdk_meta.to_json},"sent_at":"#{Sentry.utc_now.iso8601}"}
@@ -85,6 +94,12 @@ def encode(event)
 
       envelope
     end
+
+    private
+
+    def get_item_type(event_hash)
+      event_hash[:type] || event_hash["type"] || "event"
+    end
   end
 end
 

sentry-ruby/lib/sentry/transport/http_transport.rb

@@ -11,7 +11,7 @@ class HTTPTransport < Transport
     RETRY_AFTER_HEADER = "retry-after"
     RATE_LIMIT_HEADER = "x-sentry-rate-limits"
 
-    attr_reader :conn, :adapter, :rate_limits
+    attr_reader :conn, :adapter
 
     def initialize(*args)
       super

sentry-ruby/spec/sentry/hub_spec.rb

@@ -119,6 +119,7 @@
       end
     end
   end
+
   describe '#capture_message' do
     let(:message) { "Test message" }
 

sentry-ruby/spec/sentry/transport/http_transport_rate_limiting_spec.rb

@@ -21,35 +21,37 @@
 
     context "with only category limits" do
       it "returns true for still limited category" do
-        subject.rate_limits.merge!("error" => Time.now + 60)
+        subject.rate_limits.merge!("error" => Time.now + 60, "transaction" => Time.now + 60)
 
-        expect(subject.is_rate_limited?(event.to_hash)).to eq(true)
+        expect(subject.is_rate_limited?("event")).to eq(true)
+        expect(subject.is_rate_limited?("transaction")).to eq(true)
       end
 
       it "returns false for passed limited category" do
-        subject.rate_limits.merge!("error" => Time.now - 10)
+        subject.rate_limits.merge!("error" => Time.now - 10, "transaction" => Time.now - 10)
 
-        expect(subject.is_rate_limited?(event.to_hash)).to eq(false)
+        expect(subject.is_rate_limited?("event")).to eq(false)
+        expect(subject.is_rate_limited?("transaction")).to eq(false)
       end
 
       it "returns false for not listed category" do
         subject.rate_limits.merge!("transaction" => Time.now + 10)
 
-        expect(subject.is_rate_limited?(event.to_hash)).to eq(false)
+        expect(subject.is_rate_limited?("event")).to eq(false)
       end
     end
 
     context "with only universal limits" do
       it "returns true when still limited" do
         subject.rate_limits.merge!(nil => Time.now + 60)
 
-        expect(subject.is_rate_limited?(event.to_hash)).to eq(true)
+        expect(subject.is_rate_limited?("event")).to eq(true)
       end
 
       it "returns false when passed limit" do
         subject.rate_limits.merge!(nil => Time.now - 10)
 
-        expect(subject.is_rate_limited?(event.to_hash)).to eq(false)
+        expect(subject.is_rate_limited?("event")).to eq(false)
       end
     end
 
@@ -60,7 +62,7 @@
           nil => Time.now - 10
         )
 
-        expect(subject.is_rate_limited?(event.to_hash)).to eq(true)
+        expect(subject.is_rate_limited?("event")).to eq(true)
       end
     end
   end

sentry-ruby/spec/sentry/transport_spec.rb

@@ -90,7 +90,7 @@
         subject.send_event(event)
 
         logs = string_io.string
-        expect(logs).to match(/Event not sent: Excluded by random sample/)
+        expect(logs).to match(/Envelope \[event\] not sent: Excluded by random sample/)
       end
     end
 

sentry-ruby/spec/sentry_spec.rb

@@ -99,6 +99,24 @@
         expect(subject.last_event_id).to eq(nil)
       end
     end
+
+    context "when rate limited" do
+      let(:string_io) { StringIO.new }
+      before do
+        perform_basic_setup do |config|
+          config.logger = Logger.new(string_io)
+          config.transport.transport_class = Sentry::HTTPTransport
+        end
+
+        Sentry.get_current_client.transport.rate_limits.merge!("error" => Time.now + 100)
+      end
+
+      it "stops the event and logs correct message" do
+        described_class.send(capture_helper, capture_subject)
+
+        expect(string_io.string).to match(/Envelope \[event\] not sent: rate limiting/)
+      end
+    end
   end
 
   describe ".send_event" do