From 51995ece960d828fba97573bd37c0ef995654295 Mon Sep 17 00:00:00 2001 From: Frederik Erbs Spang Thomsen Date: Fri, 16 Aug 2024 20:22:34 +0200 Subject: [PATCH] Add ActiveSupport for cache module --- CHANGELOG.md | 2 + .../lib/sentry/rails/configuration.rb | 2 + .../tracing/active_support_subscriber.rb | 63 +++++++ sentry-rails/spec/dummy/test_rails_app/app.rb | 2 + .../spec/sentry/rails/configuration_spec.rb | 4 +- .../tracing/active_support_subscriber_spec.rb | 176 ++++++++++++++++++ 6 files changed, 247 insertions(+), 2 deletions(-) create mode 100644 sentry-rails/lib/sentry/rails/tracing/active_support_subscriber.rb create mode 100644 sentry-rails/spec/sentry/rails/tracing/active_support_subscriber_spec.rb diff --git a/CHANGELOG.md b/CHANGELOG.md index 4adbcb093..92c0cdc99 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,6 +3,8 @@ ### Features - Add `include_sentry_event` matcher for RSpec [#2424](https://github.com/getsentry/sentry-ruby/pull/2424) +- Add support for Sentry Cache instrumentation, when using Rails.cache ([#2380](https://github.com/getsentry/sentry-ruby/pull/2380)) + ### Bug Fixes diff --git a/sentry-rails/lib/sentry/rails/configuration.rb b/sentry-rails/lib/sentry/rails/configuration.rb index 2e4591947..a28a07f69 100644 --- a/sentry-rails/lib/sentry/rails/configuration.rb +++ b/sentry-rails/lib/sentry/rails/configuration.rb @@ -4,6 +4,7 @@ require "sentry/rails/tracing/action_view_subscriber" require "sentry/rails/tracing/active_record_subscriber" require "sentry/rails/tracing/active_storage_subscriber" +require "sentry/rails/tracing/active_support_subscriber" module Sentry class Configuration @@ -164,6 +165,7 @@ def initialize end @tracing_subscribers = Set.new([ Sentry::Rails::Tracing::ActionViewSubscriber, + Sentry::Rails::Tracing::ActiveSupportSubscriber, Sentry::Rails::Tracing::ActiveRecordSubscriber, Sentry::Rails::Tracing::ActiveStorageSubscriber ]) diff --git a/sentry-rails/lib/sentry/rails/tracing/active_support_subscriber.rb b/sentry-rails/lib/sentry/rails/tracing/active_support_subscriber.rb new file mode 100644 index 000000000..e19c22245 --- /dev/null +++ b/sentry-rails/lib/sentry/rails/tracing/active_support_subscriber.rb @@ -0,0 +1,63 @@ +# frozen_string_literal: true + +require "sentry/rails/tracing/abstract_subscriber" + +module Sentry + module Rails + module Tracing + class ActiveSupportSubscriber < AbstractSubscriber + READ_EVENT_NAMES = %w[ + cache_read.active_support + ].freeze + + WRITE_EVENT_NAMES = %w[ + cache_write.active_support + cache_increment.active_support + cache_decrement.active_support + ].freeze + + REMOVE_EVENT_NAMES = %w[ + cache_delete.active_support + ].freeze + + FLUSH_EVENT_NAMES = %w[ + cache_prune.active_support + ].freeze + + EVENT_NAMES = READ_EVENT_NAMES + WRITE_EVENT_NAMES + REMOVE_EVENT_NAMES + FLUSH_EVENT_NAMES + + SPAN_ORIGIN = "auto.cache.rails" + + def self.subscribe! + subscribe_to_event(EVENT_NAMES) do |event_name, duration, payload| + record_on_current_span( + op: operation_name(event_name), + origin: SPAN_ORIGIN, + start_timestamp: payload[START_TIMESTAMP_NAME], + description: payload[:store], + duration: duration + ) do |span| + span.set_data("cache.key", [*payload[:key]].select { |key| Utils::EncodingHelper.valid_utf_8?(key) }) + span.set_data("cache.hit", payload[:hit] == true) # Handle nil case + end + end + end + + def self.operation_name(event_name) + case + when READ_EVENT_NAMES.include?(event_name) + "cache.get" + when WRITE_EVENT_NAMES.include?(event_name) + "cache.put" + when REMOVE_EVENT_NAMES.include?(event_name) + "cache.remove" + when FLUSH_EVENT_NAMES.include?(event_name) + "cache.flush" + else + "other" + end + end + end + end + end +end diff --git a/sentry-rails/spec/dummy/test_rails_app/app.rb b/sentry-rails/spec/dummy/test_rails_app/app.rb index 7b7e926ba..4a807f587 100644 --- a/sentry-rails/spec/dummy/test_rails_app/app.rb +++ b/sentry-rails/spec/dummy/test_rails_app/app.rb @@ -58,6 +58,8 @@ def self.name app.config.logger = ActiveSupport::Logger.new(nil) app.config.eager_load = false app.config.active_job.queue_adapter = :test + app.config.cache_store = :memory_store + app.config.action_controller.perform_caching = true # Eager load namespaces can be accumulated after repeated initializations and make initialization # slower after each run diff --git a/sentry-rails/spec/sentry/rails/configuration_spec.rb b/sentry-rails/spec/sentry/rails/configuration_spec.rb index 76a8c7546..37c5a41d6 100644 --- a/sentry-rails/spec/sentry/rails/configuration_spec.rb +++ b/sentry-rails/spec/sentry/rails/configuration_spec.rb @@ -25,12 +25,12 @@ class MySubscriber; end it "returns the default subscribers" do - expect(subject.tracing_subscribers.size).to eq(3) + expect(subject.tracing_subscribers.size).to eq(4) end it "is customizable" do subject.tracing_subscribers << MySubscriber - expect(subject.tracing_subscribers.size).to eq(4) + expect(subject.tracing_subscribers.size).to eq(5) end it "is replaceable" do diff --git a/sentry-rails/spec/sentry/rails/tracing/active_support_subscriber_spec.rb b/sentry-rails/spec/sentry/rails/tracing/active_support_subscriber_spec.rb new file mode 100644 index 000000000..951ebb212 --- /dev/null +++ b/sentry-rails/spec/sentry/rails/tracing/active_support_subscriber_spec.rb @@ -0,0 +1,176 @@ +# frozen_string_literal: true + +require "spec_helper" + +RSpec.describe Sentry::Rails::Tracing::ActiveSupportSubscriber, :subscriber, type: :request do + let(:transport) do + Sentry.get_current_client.transport + end + + context "when transaction is sampled" do + before do + make_basic_app do |config, app| + config.traces_sample_rate = 1.0 + config.rails.tracing_subscribers = [described_class] + end + end + + it "tracks cache write" do + transaction = Sentry::Transaction.new(sampled: true, hub: Sentry.get_current_hub) + Sentry.get_current_scope.set_span(transaction) + + Rails.cache.write("my_cache_key", "my_cache_value") + transaction.finish + + expect(transport.events.count).to eq(1) + cache_transaction = transport.events.first.to_hash + expect(cache_transaction[:type]).to eq("transaction") + + expect(cache_transaction[:spans].count).to eq(1) + expect(cache_transaction[:spans][0][:op]).to eq("cache.put") + expect(cache_transaction[:spans][0][:origin]).to eq("auto.cache.rails") + end + + # + it "tracks cache increment" do + skip("Tracks on Rails 8.0 for all Cache Stores; Until then only MemCached and Redis Stores.") if Rails.version.to_f < 8.0 + + Rails.cache.write("my_cache_key", 0) + + transaction = Sentry::Transaction.new(sampled: true, hub: Sentry.get_current_hub) + Sentry.get_current_scope.set_span(transaction) + Rails.cache.increment("my_cache_key") + + transaction.finish + + expect(Rails.cache.read("my_cache_key")).to eq(1) + expect(transport.events.count).to eq(1) + cache_transaction = transport.events.first.to_hash + expect(cache_transaction[:type]).to eq("transaction") + expect(cache_transaction[:spans].count).to eq(2) + expect(cache_transaction[:spans][1][:op]).to eq("cache.put") + expect(cache_transaction[:spans][1][:origin]).to eq("auto.cache.rails") + end + + # + it "tracks cache decrement" do + skip("Tracks on Rails 8.0 for all Cache Stores; Until then only MemCached and Redis Stores.") if Rails.version.to_f < 8.0 + + Rails.cache.write("my_cache_key", 0) + + transaction = Sentry::Transaction.new(sampled: true, hub: Sentry.get_current_hub) + Sentry.get_current_scope.set_span(transaction) + Rails.cache.decrement("my_cache_key") + + transaction.finish + + expect(transport.events.count).to eq(1) + cache_transaction = transport.events.first.to_hash + expect(cache_transaction[:type]).to eq("transaction") + expect(cache_transaction[:spans].count).to eq(2) + expect(cache_transaction[:spans][1][:op]).to eq("cache.put") + expect(cache_transaction[:spans][1][:origin]).to eq("auto.cache.rails") + end + + it "tracks cache read" do + transaction = Sentry::Transaction.new(sampled: true, hub: Sentry.get_current_hub) + Sentry.get_current_scope.set_span(transaction) + Rails.cache.read("my_cache_key") + + transaction.finish + + expect(transport.events.count).to eq(1) + cache_transaction = transport.events.first.to_hash + expect(cache_transaction[:type]).to eq("transaction") + expect(cache_transaction[:spans].count).to eq(1) + expect(cache_transaction[:spans][0][:op]).to eq("cache.get") + expect(cache_transaction[:spans][0][:origin]).to eq("auto.cache.rails") + end + + it "tracks cache delete" do + transaction = Sentry::Transaction.new(sampled: true, hub: Sentry.get_current_hub) + Sentry.get_current_scope.set_span(transaction) + + Rails.cache.read("my_cache_key") + + transaction.finish + + expect(transport.events.count).to eq(1) + cache_transaction = transport.events.first.to_hash + expect(cache_transaction[:type]).to eq("transaction") + expect(cache_transaction[:spans].count).to eq(1) + expect(cache_transaction[:spans][0][:op]).to eq("cache.get") + expect(cache_transaction[:spans][0][:origin]).to eq("auto.cache.rails") + end + it "tracks cache prune" do + transaction = Sentry::Transaction.new(sampled: true, hub: Sentry.get_current_hub) + Sentry.get_current_scope.set_span(transaction) + + Rails.cache.write("my_cache_key", 123, expires_in: 0.seconds) + + Rails.cache.prune(0) + + transaction.finish + + expect(transport.events.count).to eq(1) + cache_transaction = transport.events.first.to_hash + expect(cache_transaction[:type]).to eq("transaction") + expect(cache_transaction[:spans].count).to eq(2) + expect(cache_transaction[:spans][1][:op]).to eq("cache.flush") + expect(cache_transaction[:spans][1][:origin]).to eq("auto.cache.rails") + end + + it "tracks sets cache hit" do + skip("cache.hit is unset on Rails 6.0.x.") if Rails.version.to_i == 6 + + Rails.cache.write("my_cache_key", "my_cache_value") + transaction = Sentry::Transaction.new(sampled: true, hub: Sentry.get_current_hub) + Sentry.get_current_scope.set_span(transaction) + Rails.cache.read("my_cache_key") + Rails.cache.read("my_cache_key_non_existing") + + transaction.finish + expect(transport.events.count).to eq(1) + cache_transaction = transport.events.first.to_hash + expect(cache_transaction[:type]).to eq("transaction") + expect(cache_transaction[:spans].count).to eq(2) + expect(cache_transaction[:spans][0][:op]).to eq("cache.get") + expect(cache_transaction[:spans][0][:origin]).to eq("auto.cache.rails") + expect(cache_transaction[:spans][0][:data]['cache.key']).to eq(["my_cache_key"]) + expect(cache_transaction[:spans][0][:data]['cache.hit']).to eq(true) + + expect(cache_transaction[:spans][1][:op]).to eq("cache.get") + expect(cache_transaction[:spans][1][:origin]).to eq("auto.cache.rails") + expect(cache_transaction[:spans][1][:data]['cache.key']).to eq(["my_cache_key_non_existing"]) + expect(cache_transaction[:spans][1][:data]['cache.hit']).to eq(false) + end + + it "tracks cache delete" do + Rails.cache.write("my_cache_key", "my_cache_value") + transaction = Sentry::Transaction.new(sampled: true, hub: Sentry.get_current_hub) + Sentry.get_current_scope.set_span(transaction) + Rails.cache.delete("my_cache_key") + + transaction.finish + expect(transport.events.count).to eq(1) + cache_transaction = transport.events.first.to_hash + expect(cache_transaction[:type]).to eq("transaction") + expect(cache_transaction[:spans].count).to eq(1) + expect(cache_transaction[:spans][0][:op]).to eq("cache.remove") + expect(cache_transaction[:spans][0][:origin]).to eq("auto.cache.rails") + expect(cache_transaction[:spans][0][:data]['cache.key']).to eq(["my_cache_key"]) + end + end + + context "when transaction is not sampled" do + before do + make_basic_app + end + + it "doesn't record spans" do + Rails.cache.write("my_cache_key", "my_cache_value") + + expect(transport.events.count).to eq(0) + end + end +end