From 69f46e170b6587731f0af0f0a68ef349651c7b2a Mon Sep 17 00:00:00 2001 From: Marco Costa Date: Thu, 27 Jun 2024 13:41:59 -0700 Subject: [PATCH] Use ActiveSupport events to instrument ActiveSupport::Cache Signed-off-by: Marco Costa --- .../contrib/active_support/cache/event.rb | 32 ++++ .../contrib/active_support/cache/events.rb | 34 ++++ .../active_support/cache/events/cache.rb | 156 ++++++++++++++++++ .../active_support/cache/instrumentation.rb | 86 +++++----- .../contrib/active_support/cache/patcher.rb | 57 ++----- .../contrib/active_support/cache/redis.rb | 5 +- .../active_support/notifications/event.rb | 12 +- .../notifications/subscriber.rb | 20 ++- .../notifications/subscription.rb | 18 +- .../contrib/active_support/cache/event.rbs | 18 ++ .../contrib/active_support/cache/events.rbs | 19 +++ .../active_support/cache/events/cache.rbs | 32 ++++ .../active_support/cache/instrumentation.rbs | 3 - .../notifications/event_spec.rb | 10 +- .../notifications/subscriber_spec.rb | 17 +- .../notifications/subscription_spec.rb | 105 +++++------- .../tracing/contrib/rails/cache_spec.rb | 10 +- .../tracing/contrib/rails/redis_cache_spec.rb | 50 ++++++ 18 files changed, 507 insertions(+), 177 deletions(-) create mode 100644 lib/datadog/tracing/contrib/active_support/cache/event.rb create mode 100644 lib/datadog/tracing/contrib/active_support/cache/events.rb create mode 100644 lib/datadog/tracing/contrib/active_support/cache/events/cache.rb create mode 100644 sig/datadog/tracing/contrib/active_support/cache/event.rbs create mode 100644 sig/datadog/tracing/contrib/active_support/cache/events.rbs create mode 100644 sig/datadog/tracing/contrib/active_support/cache/events/cache.rbs diff --git a/lib/datadog/tracing/contrib/active_support/cache/event.rb b/lib/datadog/tracing/contrib/active_support/cache/event.rb new file mode 100644 index 00000000000..d58484115d1 --- /dev/null +++ b/lib/datadog/tracing/contrib/active_support/cache/event.rb @@ -0,0 +1,32 @@ +# frozen_string_literal: true + +require_relative '../notifications/event' + +module Datadog + module Tracing + module Contrib + module ActiveSupport + module Cache + # Defines basic behaviors for an ActiveSupport event. + module Event + def self.included(base) + base.include(ActiveSupport::Notifications::Event) + base.extend(ClassMethods) + end + + # Class methods for ActiveRecord events. + module ClassMethods + def span_options + {} + end + + def configuration + Datadog.configuration.tracing[:active_support] + end + end + end + end + end + end + end +end diff --git a/lib/datadog/tracing/contrib/active_support/cache/events.rb b/lib/datadog/tracing/contrib/active_support/cache/events.rb new file mode 100644 index 00000000000..142a47f7649 --- /dev/null +++ b/lib/datadog/tracing/contrib/active_support/cache/events.rb @@ -0,0 +1,34 @@ +# frozen_string_literal: true + +require_relative 'events/cache' + +module Datadog + module Tracing + module Contrib + module ActiveSupport + module Cache + # Defines collection of instrumented ActiveSupport events + module Events + ALL = [ + Events::Cache, + ].freeze + + module_function + + def all + self::ALL + end + + def subscriptions + all.collect(&:subscriptions).collect(&:to_a).flatten + end + + def subscribe! + all.each(&:subscribe!) + end + end + end + end + end + end +end diff --git a/lib/datadog/tracing/contrib/active_support/cache/events/cache.rb b/lib/datadog/tracing/contrib/active_support/cache/events/cache.rb new file mode 100644 index 00000000000..2abec4c1d26 --- /dev/null +++ b/lib/datadog/tracing/contrib/active_support/cache/events/cache.rb @@ -0,0 +1,156 @@ +# frozen_string_literal: true + +require_relative '../../ext' +require_relative '../event' + +module Datadog + module Tracing + module Contrib + module ActiveSupport + module Cache + module Events + # Defines instrumentation for instantiation.active_record event + module Cache + include ActiveSupport::Cache::Event + + module_function + + # Acts as this module's initializer. + def subscribe! + @cache_backend = {} + super + end + + def event_name + /\Acache_(?:delete|read|read_multi|write|write_multi)\.active_support\z/ + end + + def span_name + Ext::SPAN_CACHE + end + + def span_options + { + type: Ext::SPAN_TYPE_CACHE + } + end + + # DEV: Look for other uses of `ActiveSupport::Cache::Store#instrument`, to find other useful event keys. + MAPPING = { + 'cache_delete.active_support' => { resource: Ext::RESOURCE_CACHE_DELETE }, + 'cache_read.active_support' => { resource: Ext::RESOURCE_CACHE_GET }, + 'cache_read_multi.active_support' => { resource: Ext::RESOURCE_CACHE_MGET, multi_key: true }, + 'cache_write.active_support' => { resource: Ext::RESOURCE_CACHE_SET }, + 'cache_write_multi.active_support' => { resource: Ext::RESOURCE_CACHE_MSET, multi_key: true } + }.freeze + + def trace?(event, _payload) + return false if !Tracing.enabled? || !configuration.enabled + + # DEV-3.0: Backwards compatibility code for the 2.x gem series. + # DEV-3.0: See documentation at {Datadog::Tracing::Contrib::ActiveSupport::Cache::Instrumentation} + # DEV-3.0: for the complete information about this backwards compatibility code. + case event + when 'cache_read.active_support' + !ActiveSupport::Cache::Instrumentation.nested_read? + when 'cache_read_multi.active_support' + !ActiveSupport::Cache::Instrumentation.nested_multiread? + else + true + end + end + + def on_start(span, event, _id, payload) + key = payload[:key] + store = payload[:store] + + mapping = MAPPING[event] + + span.service = configuration[:cache_service] + span.resource = mapping[:resource] + + span.set_tag(Tracing::Metadata::Ext::TAG_COMPONENT, Ext::TAG_COMPONENT) + span.set_tag(Tracing::Metadata::Ext::TAG_OPERATION, Ext::TAG_OPERATION_CACHE) + + if span.service != Datadog.configuration.service + span.set_tag(Tracing::Contrib::Ext::Metadata::TAG_BASE_SERVICE, Datadog.configuration.service) + end + + span.set_tag(Ext::TAG_CACHE_BACKEND, cache_backend(store)) + + span.set_tag('EVENT', event) + + set_cache_key(span, key, mapping[:multi_key]) + end + + def set_cache_key(span, key, multi_key) + if multi_key + keys = key.is_a?(Hash) ? key.keys : key # `write`s use Hashes, while `read`s use Arrays + resolved_key = keys.map { |k| ::ActiveSupport::Cache.expand_cache_key(k) } + cache_key = Core::Utils.truncate(resolved_key, Ext::QUANTIZE_CACHE_MAX_KEY_SIZE) + span.set_tag(Ext::TAG_CACHE_KEY_MULTI, cache_key) + else + resolved_key = ::ActiveSupport::Cache.expand_cache_key(key) + cache_key = Core::Utils.truncate(resolved_key, Ext::QUANTIZE_CACHE_MAX_KEY_SIZE) + span.set_tag(Ext::TAG_CACHE_KEY, cache_key) + end + end + + # The name of the `store` is never saved by Rails. + # ActiveSupport looks up stores by converting a symbol into a 'require' path, + # then "camelizing" it for a `const_get` call: + # ``` + # require "active_support/cache/#{store}" + # ActiveSupport::Cache.const_get(store.to_s.camelize) + # ``` + # @see https://github.com/rails/rails/blob/261975dbef77731d2c76f907f1076c5132ebc0e4/activesupport/lib/active_support/cache.rb#L139-L149 + # + # We can reverse engineer + # the original symbol by converting the class name to snake case: + # e.g. ActiveSupport::Cache::RedisStore -> active_support/cache/redis_store + # In this case, `redis_store` is the store name. + # + # Because there's no API retrieve only the class name + # (only `RedisStore`, and not `ActiveSupport::Cache::RedisStore`) + # the easiest way to retrieve the store symbol is to convert the fully qualified + # name using the Rails-provided method `#underscore`, which is the reverse of `#camelize`, + # then extracting the last part of it. + # + # Also, this method caches the store name, given this value will be retrieve + # multiple times and involves string manipulation. + def cache_backend(store) + # Cache the backend name to avoid the expensive string manipulation required to calculate it. + # DEV: We can't store it directly in the `store` object because it is a frozen String. + if (name = @cache_backend[store]) + return name + end + + # DEV: #underscore is available through ActiveSupport, and is + # DEV: the exact reverse operation to `#camelize`. + # DEV: #demodulize is available through ActiveSupport, and is + # DEV: used to remove the module ('*::') part of a constant name. + name = ::ActiveSupport::Inflector.demodulize(store) + name = ::ActiveSupport::Inflector.underscore(name) + + # Despite a given application only ever having 1-3 store types, + # we limit the size of the `@cache_backend` just in case, because + # the user can create custom Cache store classes themselves. + @cache_backend[store] = name if @cache_backend.size < 50 + + name + end + + # DEV: There are two possibly interesting fields in the `on_finish` payload: + # | `:hit` | If this read is a hit | + # | `:super_operation` | `:fetch` if a read is done with [`fetch`][ActiveSupport::Cache::Store#fetch] | + # @see https://github.com/rails/rails/blob/b9d6759401c3d50a51e0a7650cb2331f4218d11f/guides/source/active_support_instrumentation.md?plain=1#L528-L529 + # def on_finish(span, event, id, payload) + # super + # end + end + end + end + end + end + end +end diff --git a/lib/datadog/tracing/contrib/active_support/cache/instrumentation.rb b/lib/datadog/tracing/contrib/active_support/cache/instrumentation.rb index ebf9e397ee2..13c92a08418 100644 --- a/lib/datadog/tracing/contrib/active_support/cache/instrumentation.rb +++ b/lib/datadog/tracing/contrib/active_support/cache/instrumentation.rb @@ -9,7 +9,31 @@ module Tracing module Contrib module ActiveSupport module Cache - # Defines instrumentation for ActiveSupport caching + # DEV-3.0: Backwards compatibility code for the 2.x gem series. + # DEV-3.0: + # DEV-3.0: `ActiveSupport::Cache` is now instrumented by subscribing to ActiveSupport::Notifications events. + # DEV-3.0: The implementation is located at {Datadog::Tracing::Contrib::ActiveSupport::Cache::Events::Cache}. + # DEV-3.0: The events emitted provide richer introspection points (e.g. events for cache misses on `#fetch`) while + # DEV-3.0: also ensuring we are using Rails' public API for improved compatibility. + # DEV-3.0: + # DEV-3.0: But a few operations holds us back: + # DEV-3.0: 1. `ActiveSupport::Cache::Store#fetch`: + # DEV-3.0: This method does not have an event that can produce an equivalent span to today's 2.x implementation. + # DEV-3.0: In 2.x, `#fetch` produces two separate, *nested* spans: one for the `#read` operation and + # DEV-3.0: another for the `#write` operation that is called internally by `#fetch` when the cache key needs + # DEV-3.0: to be populated on a cache miss. + # DEV-3.0: But the ActiveSupport events emitted by `#fetch` provide two *sibling* events for the`#read` and + # DEV-3.0: `#write` operations. + # DEV-3.0: Moving from nested spans to sibling spans would be a breaking change. One notable difference is + # DEV-3.0: that if the nested `#write` operation fails 2.x, the `#read` span is marked as an error. This would + # DEV-3.0: not be the case with sibling spans, and would be a very visible change. + # DEV-3.0: 2. `ActiveSupport::Cache::Store#read_multi` & `ActiveSupport::Cache::Store#fetch_multi`: + # DEV-3.0: ActiveSupport events were introduced in ActiveSupport 5.2.0 for these methods. + # DEV-3.0: + # DEV-3.0: At the end of the day, moving to ActiveSupport events is the better approach, but we have to retain + # DEV-3.0: this last few monkey patches (and all the supporting code) to avoid a breaking change for now. + # + # Defines the deprecate monkey-patch instrumentation for `ActiveSupport::Cache::Store#fetch` module Instrumentation module_function @@ -43,6 +67,10 @@ def trace(action, store, key: nil, multi_key: nil) # In most of the cases, `#fetch()` and `#read()` calls are nested. # Instrument both does not add any value. # This method checks if these two operations are nested. + # + # DEV-3.0: We should not have these checks in the 3.x series because ActiveSupport events provide more + # DEV-3.0: legible nested spans. While using ActiveSupport events, the nested spans actually provide meaningful + # DEV-3.0: information. def nested_read? current_span = Tracing.active_span current_span && current_span.name == Ext::SPAN_CACHE && current_span.resource == Ext::RESOURCE_CACHE_GET @@ -107,29 +135,20 @@ def dd_store_name end end - # Defines instrumentation for ActiveSupport cache reading - module Read - include InstanceMethods - - def read(*args, &block) - return super if Instrumentation.nested_read? - - Instrumentation.trace(Ext::RESOURCE_CACHE_GET, dd_store_name, key: args[0]) { super } - end - end - - # Defines instrumentation for ActiveSupport cache reading of multiple keys + # Defines the the legacy monkey-patching instrumentation for ActiveSupport cache read_multi + # DEV-3.0: ActiveSupport::Notifications events were introduced in ActiveSupport 5.2.0 for this method. + # DEV-3.0: As long as we support ActiveSupport < 5.2.0, we have to keep this method. module ReadMulti include InstanceMethods - def read_multi(*keys, &block) + def read_multi(*keys, **options, &block) return super if Instrumentation.nested_multiread? Instrumentation.trace(Ext::RESOURCE_CACHE_MGET, dd_store_name, multi_key: keys) { super } end end - # Defines instrumentation for ActiveSupport cache fetching + # Defines the the legacy monkey-patching instrumentation for ActiveSupport cache fetch module Fetch include InstanceMethods @@ -140,11 +159,13 @@ def fetch(*args, &block) end end - # Defines instrumentation for ActiveSupport cache fetching of multiple keys + # Defines the the legacy monkey-patching instrumentation for ActiveSupport cache fetch_multi + # DEV-3.0: ActiveSupport::Notifications events were introduced in ActiveSupport 5.2.0 for this method. + # DEV-3.0: As long as we support ActiveSupport < 5.2.0, we have to keep this method. module FetchMulti include InstanceMethods - def fetch_multi(*args, &block) + def fetch_multi(*args, **options, &block) return super if Instrumentation.nested_multiread? keys = args[-1].instance_of?(Hash) ? args[0..-2] : args @@ -152,30 +173,13 @@ def fetch_multi(*args, &block) end end - # Defines instrumentation for ActiveSupport cache writing - module Write - include InstanceMethods - - def write(*args, &block) - Instrumentation.trace(Ext::RESOURCE_CACHE_SET, dd_store_name, key: args[0]) { super } - end - end - - # Defines instrumentation for ActiveSupport cache writing of multiple keys - module WriteMulti - include InstanceMethods - - def write_multi(hash, options = nil) - Instrumentation.trace(Ext::RESOURCE_CACHE_MSET, dd_store_name, multi_key: hash.keys) { super } - end - end - - # Defines instrumentation for ActiveSupport cache deleting - module Delete - include InstanceMethods - - def delete(*args, &block) - Instrumentation.trace(Ext::RESOURCE_CACHE_DELETE, dd_store_name, key: args[0]) { super } + # Backports the payload[:store] key present since Rails 6.1: + # https://github.com/rails/rails/commit/6fa747f2946ee244b2aab0cd8c3c064f05d950a5 + module Store + def instrument(operation, key, options = nil) + polyfill_options = options&.dup || {} + polyfill_options[:store] = self.class.name + super(operation, key, polyfill_options) end end end diff --git a/lib/datadog/tracing/contrib/active_support/cache/patcher.rb b/lib/datadog/tracing/contrib/active_support/cache/patcher.rb index 2d1431732e1..d78a9c16940 100644 --- a/lib/datadog/tracing/contrib/active_support/cache/patcher.rb +++ b/lib/datadog/tracing/contrib/active_support/cache/patcher.rb @@ -2,6 +2,7 @@ require_relative '../../patcher' require_relative 'instrumentation' +require_relative 'events' module Datadog module Tracing @@ -19,54 +20,30 @@ def target_version end def patch - patch_cache_store_read - patch_cache_store_read_multi - patch_cache_store_fetch - patch_cache_store_fetch_multi - patch_cache_store_write - patch_cache_store_write_multi - patch_cache_store_delete + Events.subscribe! + + # Backfill the `:store` key in the ActiveSupport event payload for older Rails. + if Integration.version < Gem::Version.new('6.1.0') + ::ActiveSupport::Cache::Store.prepend(Cache::Instrumentation::Store) + end + + # DEV-3.0: Backwards compatibility code for the 2.x gem series. + # DEV-3.0: See documentation at {Datadog::Tracing::Contrib::ActiveSupport::Cache::Instrumentation} + # DEV-3.0: for the complete information about this backwards compatibility code. + patch_legacy_cache_store end # This method is overwritten by # `datadog/tracing/contrib/active_support/cache/redis.rb` # with more complex behavior. def cache_store_class(meth) - ::ActiveSupport::Cache::Store - end - - def patch_cache_store_read - cache_store_class(:read).prepend(Cache::Instrumentation::Read) - end - - def patch_cache_store_read_multi - cache_store_class(:read_multi).prepend(Cache::Instrumentation::ReadMulti) - end - - def patch_cache_store_fetch - cache_store_class(:fetch).prepend(Cache::Instrumentation::Fetch) - end - - def patch_cache_store_fetch_multi - klass = cache_store_class(:fetch_multi) - return unless klass.public_method_defined?(:fetch_multi) - - klass.prepend(Cache::Instrumentation::FetchMulti) - end - - def patch_cache_store_write - cache_store_class(:write).prepend(Cache::Instrumentation::Write) - end - - def patch_cache_store_write_multi - klass = cache_store_class(:write_multi) - return unless klass.public_method_defined?(:write_multi) - - klass.prepend(Cache::Instrumentation::WriteMulti) + [::ActiveSupport::Cache::Store] end - def patch_cache_store_delete - cache_store_class(:delete).prepend(Cache::Instrumentation::Delete) + def patch_legacy_cache_store + cache_store_class(:read_multi).each { |clazz| clazz.prepend(Cache::Instrumentation::ReadMulti) } + cache_store_class(:fetch).each { |clazz| clazz.prepend(Cache::Instrumentation::Fetch) } + cache_store_class(:fetch_multi).each { |clazz| clazz.prepend(Cache::Instrumentation::FetchMulti) } end end end diff --git a/lib/datadog/tracing/contrib/active_support/cache/redis.rb b/lib/datadog/tracing/contrib/active_support/cache/redis.rb index 90d4bba8429..4004ab4a136 100644 --- a/lib/datadog/tracing/contrib/active_support/cache/redis.rb +++ b/lib/datadog/tracing/contrib/active_support/cache/redis.rb @@ -30,7 +30,10 @@ def patch_redis?(meth) def cache_store_class(meth) if patch_redis?(meth) - ::ActiveSupport::Cache::RedisStore + [::ActiveSupport::Cache::RedisStore, ::ActiveSupport::Cache::Store] + elsif Gem.loaded_specs['redis'] && defined?(::ActiveSupport::Cache::RedisCacheStore) \ + && ::ActiveSupport::Cache::RedisCacheStore.instance_methods(false).include?(meth) + [::ActiveSupport::Cache::RedisCacheStore, ::ActiveSupport::Cache::Store] else super end diff --git a/lib/datadog/tracing/contrib/active_support/notifications/event.rb b/lib/datadog/tracing/contrib/active_support/notifications/event.rb index 68381af1957..07f8b0ae268 100644 --- a/lib/datadog/tracing/contrib/active_support/notifications/event.rb +++ b/lib/datadog/tracing/contrib/active_support/notifications/event.rb @@ -26,12 +26,13 @@ def subscribe! # rubocop:disable Lint/UselessMethodDefinition super end - def subscription(span_name = nil, span_options = nil, on_start: nil, on_finish: nil) + def subscription(span_name = nil, span_options = nil, on_start: nil, on_finish: nil, trace: nil) super( span_name || self.span_name, span_options || self.span_options, on_start: on_start, - on_finish: on_finish + on_finish: on_finish, + trace: trace ) end @@ -42,7 +43,8 @@ def subscribe(pattern = nil, span_name = nil, span_options = nil) span_name || self.span_name, span_options || self.span_options, on_start: method(:on_start), - on_finish: method(:on_finish) + on_finish: method(:on_finish), + trace: method(:trace?) ) end end @@ -71,6 +73,10 @@ def on_finish(span, _event, _id, payload) record_exception(span, payload) end + def trace?(_event, _payload) + true + end + def record_exception(span, payload) if payload[:exception_object] span.set_error(payload[:exception_object]) diff --git a/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb b/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb index 37d12c6507a..c0acc74db25 100644 --- a/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb +++ b/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb @@ -45,16 +45,28 @@ def subscribe! end # Creates a subscription and immediately activates it. - def subscribe(pattern, span_name, span_options = {}, on_start: nil, on_finish: nil) - subscription(span_name, span_options, on_start: on_start, on_finish: on_finish).tap do |subscription| + def subscribe(pattern, span_name, span_options = {}, on_start: nil, on_finish: nil, trace: nil) + subscription( + span_name, + span_options, + on_start: on_start, + on_finish: on_finish, + trace: trace + ).tap do |subscription| subscription.subscribe(pattern) end end # Creates a subscription without activating it. # Subscription is added to the inheriting class' list of subscriptions. - def subscription(span_name, span_options = {}, on_start: nil, on_finish: nil) - Subscription.new(span_name, span_options, on_start: on_start, on_finish: on_finish).tap do |subscription| + def subscription(span_name, span_options = {}, on_start: nil, on_finish: nil, trace: nil) + Subscription.new( + span_name, + span_options, + on_start: on_start, + on_finish: on_finish, + trace: trace + ).tap do |subscription| subscriptions << subscription end end diff --git a/lib/datadog/tracing/contrib/active_support/notifications/subscription.rb b/lib/datadog/tracing/contrib/active_support/notifications/subscription.rb index 972baf010cc..fffa0062f7f 100644 --- a/lib/datadog/tracing/contrib/active_support/notifications/subscription.rb +++ b/lib/datadog/tracing/contrib/active_support/notifications/subscription.rb @@ -17,30 +17,26 @@ class Subscription # might not include all required information in the `payload` argument. # @param on_finish [Proc] a block to run when the event has finished processing, # possibly including more information in the `payload` argument. - def initialize(span_name, span_options, on_start: nil, on_finish: nil) + # @param trace [Proc] whether to trace the event. Defaults to returning `true`. + def initialize(span_name, span_options, on_start: nil, on_finish: nil, trace: nil) raise ArgumentError, 'Must be given either on_start or on_finish' unless on_start || on_finish @span_name = span_name @span_options = span_options @on_start = Handler.new(on_start) @on_finish = Handler.new(on_finish) + @trace = trace @callbacks = Callbacks.new end - # ActiveSupport 3.x calls this - def call(name, start, finish, id, payload) - start_span(name, id, payload, start) - finish_span(name, id, payload, finish) - end - - # ActiveSupport 4+ calls this on start + # Called by ActiveSupport on event start def start(name, id, payload) - start_span(name, id, payload) + start_span(name, id, payload) if @trace&.call(name, payload) end - # ActiveSupport 4+ calls this on finish + # Called by ActiveSupport on event finish def finish(name, id, payload) - finish_span(name, id, payload) + finish_span(name, id, payload) if payload[:datadog_span] end def before_trace(&block) diff --git a/sig/datadog/tracing/contrib/active_support/cache/event.rbs b/sig/datadog/tracing/contrib/active_support/cache/event.rbs new file mode 100644 index 00000000000..fd62b5f18c0 --- /dev/null +++ b/sig/datadog/tracing/contrib/active_support/cache/event.rbs @@ -0,0 +1,18 @@ +module Datadog + module Tracing + module Contrib + module ActiveSupport + module Cache + module Event + def self.included: (untyped base) -> untyped + module ClassMethods + def span_options: () -> ::Hash[untyped, untyped] + + def configuration: () -> untyped + end + end + end + end + end + end +end diff --git a/sig/datadog/tracing/contrib/active_support/cache/events.rbs b/sig/datadog/tracing/contrib/active_support/cache/events.rbs new file mode 100644 index 00000000000..c374d9b48b8 --- /dev/null +++ b/sig/datadog/tracing/contrib/active_support/cache/events.rbs @@ -0,0 +1,19 @@ +module Datadog + module Tracing + module Contrib + module ActiveSupport + module Cache + module Events + ALL: ::Array[untyped] + + def self?.all: () -> untyped + + def self?.subscriptions: () -> untyped + + def self?.subscribe!: () -> untyped + end + end + end + end + end +end diff --git a/sig/datadog/tracing/contrib/active_support/cache/events/cache.rbs b/sig/datadog/tracing/contrib/active_support/cache/events/cache.rbs new file mode 100644 index 00000000000..8ceaca8567d --- /dev/null +++ b/sig/datadog/tracing/contrib/active_support/cache/events/cache.rbs @@ -0,0 +1,32 @@ +module Datadog + module Tracing + module Contrib + module ActiveSupport + module Cache + module Events + module Cache + @cache_backend: untyped + + include ActiveSupport::Cache::Event + def self?.subscribe!: () -> untyped + + def self?.event_name: () -> ::Regexp + + def self?.span_name: () -> untyped + + def self?.span_options: () -> { type: untyped } + MAPPING: ::Hash[::String, { resource: untyped } | { resource: untyped, multi_key: true }] + + def self?.trace?: (untyped event, untyped _payload) -> (false | untyped) + + def self?.on_start: (untyped span, untyped event, untyped _id, untyped payload) -> untyped + + def self?.set_cache_key: (untyped span, untyped key, untyped multi_key) -> untyped + def self?.cache_backend: (untyped store) -> untyped + end + end + end + end + end + end +end diff --git a/sig/datadog/tracing/contrib/active_support/cache/instrumentation.rbs b/sig/datadog/tracing/contrib/active_support/cache/instrumentation.rbs index 92f03550b61..44ed513ce7d 100644 --- a/sig/datadog/tracing/contrib/active_support/cache/instrumentation.rbs +++ b/sig/datadog/tracing/contrib/active_support/cache/instrumentation.rbs @@ -26,9 +26,6 @@ module Datadog module Write def write: (*untyped args) ?{ () -> untyped } -> untyped end - module WriteMulti - def write_multi: (untyped hash, ?untyped? options) -> untyped - end module Delete def delete: (*untyped args) ?{ () -> untyped } -> untyped end diff --git a/spec/datadog/tracing/contrib/active_support/notifications/event_spec.rb b/spec/datadog/tracing/contrib/active_support/notifications/event_spec.rb index 99497c3a093..62f0a7c5344 100644 --- a/spec/datadog/tracing/contrib/active_support/notifications/event_spec.rb +++ b/spec/datadog/tracing/contrib/active_support/notifications/event_spec.rb @@ -26,7 +26,8 @@ let(:callbacks) do { on_start: test_class.method(:on_start), - on_finish: test_class.method(:on_finish) + on_finish: test_class.method(:on_finish), + trace: test_class.method(:trace?) } end @@ -99,16 +100,19 @@ end context 'when given options' do - subject(:subscription) { test_class.subscription(span_name, options, on_start: on_start, on_finish: on_finish) } + subject(:subscription) do + test_class.subscription(span_name, options, on_start: on_start, on_finish: on_finish, trace: trace) + end let(:span_name) { double('span name') } let(:options) { double('options') } let(:on_start) { double('on_start') } let(:on_finish) { double('on_finish') } + let(:trace) { double('trace') } before do expect(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription).to receive(:new) - .with(span_name, options, on_start: on_start, on_finish: on_finish) + .with(span_name, options, on_start: on_start, on_finish: on_finish, trace: trace) .and_call_original end diff --git a/spec/datadog/tracing/contrib/active_support/notifications/subscriber_spec.rb b/spec/datadog/tracing/contrib/active_support/notifications/subscriber_spec.rb index 710002adbc7..70bee8c2fc3 100644 --- a/spec/datadog/tracing/contrib/active_support/notifications/subscriber_spec.rb +++ b/spec/datadog/tracing/contrib/active_support/notifications/subscriber_spec.rb @@ -15,6 +15,7 @@ describe 'behavior' do let(:on_start) { double('on start') } let(:on_finish) { double('on finish') } + let(:trace) { double('trace') } describe '#subscriptions' do subject(:subscriptions) { test_class.subscriptions } @@ -92,7 +93,15 @@ describe '#subscribe' do subject(:subscription) do - test_class.send(:subscribe, pattern, span_name, options, on_start: on_start, on_finish: on_finish) + test_class.send( + :subscribe, + pattern, + span_name, + options, + on_start: on_start, + on_finish: on_finish, + trace: trace + ) end let(:pattern) { double('pattern') } @@ -101,7 +110,7 @@ before do expect(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription).to receive(:new) - .with(span_name, options, on_start: on_start, on_finish: on_finish) + .with(span_name, options, on_start: on_start, on_finish: on_finish, trace: trace) .and_call_original expect_any_instance_of(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription) @@ -115,7 +124,7 @@ describe '#subscription' do subject(:subscription) do - test_class.send(:subscription, span_name, options, on_start: on_start, on_finish: on_finish) + test_class.send(:subscription, span_name, options, on_start: on_start, on_finish: on_finish, trace: trace) end let(:span_name) { double('span name') } @@ -123,7 +132,7 @@ before do expect(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription).to receive(:new) - .with(span_name, options, on_start: on_start, on_finish: on_finish) + .with(span_name, options, on_start: on_start, on_finish: on_finish, trace: trace) .and_call_original end diff --git a/spec/datadog/tracing/contrib/active_support/notifications/subscription_spec.rb b/spec/datadog/tracing/contrib/active_support/notifications/subscription_spec.rb index 11e00b2e030..d4cc94c702e 100644 --- a/spec/datadog/tracing/contrib/active_support/notifications/subscription_spec.rb +++ b/spec/datadog/tracing/contrib/active_support/notifications/subscription_spec.rb @@ -6,79 +6,21 @@ RSpec.describe Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription do describe 'instance' do - subject(:subscription) { described_class.new(span_name, options, on_start: on_start, on_finish: on_finish) } + subject(:subscription) do + described_class.new(span_name, options, on_start: on_start, on_finish: on_finish, trace: trace) + end let(:span_name) { double('span_name') } let(:options) { { resource: 'dummy_resource' } } let(:on_start) { proc { |span_op, name, id, payload| on_start_spy.call(span_op, name, id, payload) } } let(:on_finish) { proc { |span_op, name, id, payload| on_finish_spy.call(span_op, name, id, payload) } } + let(:trace) { proc { |_name, _payload| true } } let(:payload) { {} } let(:on_start_spy) { double('on_start_spy') } let(:on_finish_spy) { double('on_finish_spy') } describe 'behavior' do - describe '#call' do - subject(:result) { subscription.call(name, start, finish, id, payload) } - - let(:name) { double('name') } - let(:start) { double('start') } - let(:finish) { double('finish') } - let(:id) { double('id') } - let(:payload) { {} } - - let(:span_op) { instance_double(Datadog::Tracing::SpanOperation) } - - before do - allow(on_start_spy).to receive(:call).with(span_op, name, id, payload) - allow(on_finish_spy).to receive(:call).with(span_op, name, id, payload) - end - - it do - expect(Datadog::Tracing).to receive(:trace).with(span_name, **options).and_return(span_op).ordered - expect(span_op).to receive(:start).with(start).and_return(span_op).ordered - expect(on_start_spy).to receive(:call).with(span_op, name, id, payload).ordered - expect(on_finish_spy).to receive(:call).with(span_op, name, id, payload).ordered - expect(span_op).to receive(:finish).with(finish).and_return(span_op).ordered - is_expected.to be(span_op) - end - - context 'when on_start raises an error' do - let(:on_start) do - proc do |_span_op, _name, _id, _payload| - raise ArgumentError, 'Fail!' - end - end - - around { |example| without_errors { example.run } } - - it 'finishes tracing anyways' do - expect(Datadog::Tracing).to receive(:trace).with(span_name, **options).and_return(span_op).ordered - expect(span_op).to receive(:start).with(start).and_return(span_op).ordered - expect(span_op).to receive(:finish).with(finish).and_return(span_op).ordered - is_expected.to be(span_op) - end - end - - context 'when on_finish raises an error' do - let(:on_finish) do - proc do |_span_op, _name, _id, _payload| - raise ArgumentError, 'Fail!' - end - end - - around { |example| without_errors { example.run } } - - it 'finishes tracing anyways' do - expect(Datadog::Tracing).to receive(:trace).with(span_name, **options).and_return(span_op).ordered - expect(span_op).to receive(:start).with(start).and_return(span_op) - expect(span_op).to receive(:finish) - expect(on_start_spy).to receive(:call).with(span_op, name, id, payload).ordered - is_expected.to be(span_op) - end - end - end - describe '#start' do subject(:result) { subscription.start(name, id, payload) } @@ -92,6 +34,7 @@ expect(on_start_spy).to receive(:call).with(span_op, name, id, payload) expect(Datadog::Tracing).to receive(:trace).with(span_name, **options).and_return(span_op) is_expected.to be(span_op) + expect(payload[:datadog_span]).to eq(span_op) end it 'sets the parent span operation' do @@ -104,6 +47,17 @@ expect(Datadog::Tracing).to receive(:trace).with(span_name, **options).and_return(span_op) expect { subject }.to change { payload[:datadog_span] }.to be(span_op) end + + context 'with trace? returning false' do + let(:trace) { proc { |_name, _payload| false } } + + it 'does not start a span operation nor call the callback' do + expect(Datadog::Tracing).not_to receive(:trace) + expect(on_start_spy).to_not receive(:call) + is_expected.to be_nil + expect(payload[:datadog_span]).to be_nil + end + end end describe '#finish' do @@ -120,6 +74,15 @@ expect(span_op).to receive(:finish).and_return(span_op).ordered is_expected.to be(span_op) end + + context 'without a span started' do + let(:payload) { {} } + + it 'does not call the callback' do + expect(on_finish_spy).to_not receive(:call) + is_expected.to be_nil + end + end end describe '#before_trace' do @@ -158,6 +121,15 @@ it_behaves_like 'a before_trace callback' end + + context 'with trace? returning false' do + let(:trace) { proc { |_name, _payload| false } } + + it 'does not call the callback' do + expect(callback_spy).not_to receive(:call) + subscription.start(double('name'), double('id'), payload) + end + end end end @@ -200,6 +172,15 @@ it_behaves_like 'an after_trace callback' end + + context 'with trace? returning false' do + let(:trace) { proc { |_name, _payload| false } } + + it 'does not call the callback' do + expect(callback_spy).not_to receive(:call) + subscription.finish(double('name'), double('id'), payload) + end + end end end diff --git a/spec/datadog/tracing/contrib/rails/cache_spec.rb b/spec/datadog/tracing/contrib/rails/cache_spec.rb index 6e889109b6e..0a7ba0dda2f 100644 --- a/spec/datadog/tracing/contrib/rails/cache_spec.rb +++ b/spec/datadog/tracing/contrib/rails/cache_spec.rb @@ -172,7 +172,9 @@ end context 'with custom cache_service' do - before { Datadog.configuration.tracing[:active_support][:cache_service] = 'service-cache' } + before do + Datadog.configuration.tracing[:active_support][:cache_service] = 'service-cache' + end it 'uses the proper service name' do write @@ -242,14 +244,12 @@ context 'when the method is not defined' do before do - if ::ActiveSupport::Cache::Store.public_method_defined?(:write_multi) - skip 'Test is not applicable to this Rails version' - end + skip 'Test is not applicable to this Rails version' if ::ActiveSupport::Cache::Store.public_method_defined?(:fetch) end it do expect(::ActiveSupport::Cache::Store.ancestors).not_to( - include(::Datadog::Tracing::Contrib::ActiveSupport::Cache::Instrumentation::WriteMulti) + include(::Datadog::Tracing::Contrib::ActiveSupport::Cache::Instrumentation::Fetch) ) end diff --git a/spec/datadog/tracing/contrib/rails/redis_cache_spec.rb b/spec/datadog/tracing/contrib/rails/redis_cache_spec.rb index 8facb31ce00..fc3fad69e7e 100644 --- a/spec/datadog/tracing/contrib/rails/redis_cache_spec.rb +++ b/spec/datadog/tracing/contrib/rails/redis_cache_spec.rb @@ -75,6 +75,7 @@ before { cache.write(key, 50) } it do + read expect(read).to eq(50) expect(spans).to have(4).items @@ -94,6 +95,47 @@ .to eq('active_support') expect(cache.get_tag(Datadog::Tracing::Metadata::Ext::TAG_OPERATION)) .to eq('cache') + + expect(cache.get_tag('rails.cache.key')).to eq(key) + end + + it_behaves_like 'a peer service span' do + let(:span) { spans.last } + end + end + + shared_examples 'multi reader method' do |method, fetch = false| + subject(:read_multi) { cache.public_send(method, *multi_keys) {} } + + let(:multi_keys) { %w[custom-key-1 custom-key-2 custom-key-3] } + + before do + multi_keys.each { |key| cache.write(key, 50 + key[-1].to_i) } + clear_traces! + end + + it do + expect(read_multi).to eq(Hash[multi_keys.zip([51, 52, 53])]) + cache, *redises = spans + expect(redises).to have(fetch ? 2 : 1).items # Fetch will have an extra MSET redis span + redis = Rails::VERSION::MAJOR < 5 ? redises.first : redises.last + expect(cache.get_tag('rails.cache.backend')).to eq(cache_store_name) + + expect(redis.name).to eq('redis.command') + expect(redis.type).to eq('redis') + expect(redis.resource).to eq('MGET') + expect(redis.get_tag('redis.raw_command')).to eq('MGET custom-key-1 custom-key-2 custom-key-3') + expect(redis.service).to eq('redis') + # the following ensures span will be correctly displayed (parent/child of the same trace) + expect(cache.trace_id).to eq(redis.trace_id) + expect(cache.id).to eq(redis.parent_id) + + expect(cache.get_tag(Datadog::Tracing::Metadata::Ext::TAG_COMPONENT)) + .to eq('active_support') + expect(cache.get_tag(Datadog::Tracing::Metadata::Ext::TAG_OPERATION)) + .to eq('cache') + + expect(cache.get_tag('rails.cache.keys')).to eq(multi_keys.to_s) end it_behaves_like 'a peer service span' do @@ -105,6 +147,10 @@ it_behaves_like 'reader method', :read end + describe '#read_multi' do + it_behaves_like 'multi reader method', :read_multi + end + describe '#fetch' do it_behaves_like 'reader method', :fetch @@ -156,6 +202,10 @@ end end + describe '#fetch_multi' do + it_behaves_like 'multi reader method', :fetch_multi, true + end + describe '#write' do subject!(:write) { cache.write(key, 50) }