From 43e63cffb4551dbd9aa3bbccf2a5d1b532088773 Mon Sep 17 00:00:00 2001 From: Marco Costa Date: Tue, 18 Jun 2024 15:57:32 -0700 Subject: [PATCH 1/3] Populate ActiveSupport notification spans early Signed-off-by: Marco Costa --- .../tracing/contrib/action_cable/event.rb | 2 +- .../contrib/action_cable/events/broadcast.rb | 2 +- .../action_cable/events/perform_action.rb | 2 +- .../contrib/action_cable/events/transmit.rb | 2 +- .../tracing/contrib/action_mailer/event.rb | 10 ++-- .../contrib/action_mailer/events/deliver.rb | 13 +++-- .../contrib/action_mailer/events/process.rb | 5 +- .../action_view/events/render_partial.rb | 6 +-- .../action_view/events/render_template.rb | 2 +- .../contrib/active_job/events/discard.rb | 2 +- .../contrib/active_job/events/enqueue.rb | 2 +- .../contrib/active_job/events/enqueue_at.rb | 2 +- .../active_job/events/enqueue_retry.rb | 2 +- .../contrib/active_job/events/perform.rb | 2 +- .../active_job/events/retry_stopped.rb | 2 +- .../active_model_serializers/events/render.rb | 2 +- .../events/serialize.rb | 2 +- .../active_record/events/instantiation.rb | 2 +- .../contrib/active_record/events/sql.rb | 2 +- .../active_support/notifications/event.rb | 23 ++++++-- .../notifications/subscriber.rb | 8 +-- .../notifications/subscription.rb | 38 +++++++++----- .../tracing/contrib/kafka/consumer_event.rb | 2 +- .../contrib/kafka/consumer_group_event.rb | 2 +- lib/datadog/tracing/contrib/kafka/event.rb | 2 +- .../kafka/events/connection/request.rb | 6 +-- .../kafka/events/consumer/process_batch.rb | 6 +-- .../kafka/events/consumer/process_message.rb | 6 +-- .../kafka/events/consumer_group/heartbeat.rb | 6 +-- .../events/produce_operation/send_messages.rb | 6 +-- .../kafka/events/producer/deliver_messages.rb | 6 +-- lib/datadog/tracing/contrib/racecar/event.rb | 4 +- .../notifications/event_spec.rb | 24 +++++---- .../notifications/subscriber_spec.rb | 20 ++++--- .../notifications/subscription_spec.rb | 52 ++++++++++++++----- .../tracing/contrib/rails/rack_spec.rb | 12 ++--- 36 files changed, 177 insertions(+), 110 deletions(-) diff --git a/lib/datadog/tracing/contrib/action_cable/event.rb b/lib/datadog/tracing/contrib/action_cable/event.rb index 11aa6d4fab3..3e1c4aaa039 100644 --- a/lib/datadog/tracing/contrib/action_cable/event.rb +++ b/lib/datadog/tracing/contrib/action_cable/event.rb @@ -46,7 +46,7 @@ def self.included(base) module ClassMethods include Contrib::ActionCable::Event::ClassMethods - def subscription(*args) + def subscription(*args, **kwargs) super.tap do |subscription| subscription.before_trace { ensure_clean_context! } end diff --git a/lib/datadog/tracing/contrib/action_cable/events/broadcast.rb b/lib/datadog/tracing/contrib/action_cable/events/broadcast.rb index 7e2fde702be..6a874e439d1 100644 --- a/lib/datadog/tracing/contrib/action_cable/events/broadcast.rb +++ b/lib/datadog/tracing/contrib/action_cable/events/broadcast.rb @@ -34,7 +34,7 @@ def span_type Tracing::Metadata::Ext::AppTypes::TYPE_WEB end - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) channel = payload[:broadcasting] # Channel has high cardinality span.service = configuration[:service_name] if configuration[:service_name] span.type = span_type diff --git a/lib/datadog/tracing/contrib/action_cable/events/perform_action.rb b/lib/datadog/tracing/contrib/action_cable/events/perform_action.rb index 16de51e0450..24d4e547b62 100644 --- a/lib/datadog/tracing/contrib/action_cable/events/perform_action.rb +++ b/lib/datadog/tracing/contrib/action_cable/events/perform_action.rb @@ -33,7 +33,7 @@ def span_type Tracing::Metadata::Ext::AppTypes::TYPE_WEB end - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) channel_class = payload[:channel_class] action = payload[:action] diff --git a/lib/datadog/tracing/contrib/action_cable/events/transmit.rb b/lib/datadog/tracing/contrib/action_cable/events/transmit.rb index 6b612ef864a..714050b8036 100644 --- a/lib/datadog/tracing/contrib/action_cable/events/transmit.rb +++ b/lib/datadog/tracing/contrib/action_cable/events/transmit.rb @@ -33,7 +33,7 @@ def span_type Tracing::Metadata::Ext::AppTypes::TYPE_WEB end - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) channel_class = payload[:channel_class] span.service = configuration[:service_name] if configuration[:service_name] diff --git a/lib/datadog/tracing/contrib/action_mailer/event.rb b/lib/datadog/tracing/contrib/action_mailer/event.rb index f62d8eed64b..5189503627f 100644 --- a/lib/datadog/tracing/contrib/action_mailer/event.rb +++ b/lib/datadog/tracing/contrib/action_mailer/event.rb @@ -27,9 +27,11 @@ def configuration Datadog.configuration.tracing[:action_mailer] end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) + super + + span.type = span_type span.service = configuration[:service_name] if configuration[:service_name] - span.resource = payload[:mailer] span.set_tag(Tracing::Metadata::Ext::TAG_COMPONENT, Ext::TAG_COMPONENT) # Set analytics sample rate @@ -39,10 +41,6 @@ def process(span, event, _id, payload) # Measure service stats Contrib::Analytics.set_measured(span) - - report_if_exception(span, payload) - rescue StandardError => e - Datadog.logger.debug(e.message) end end end diff --git a/lib/datadog/tracing/contrib/action_mailer/events/deliver.rb b/lib/datadog/tracing/contrib/action_mailer/events/deliver.rb index 3c036d0c171..4b72640d9d6 100644 --- a/lib/datadog/tracing/contrib/action_mailer/events/deliver.rb +++ b/lib/datadog/tracing/contrib/action_mailer/events/deliver.rb @@ -30,15 +30,20 @@ def span_type Tracing::Metadata::Ext::AppTypes::TYPE_WORKER end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) super - span.type = span_type + span.set_tag(Tracing::Metadata::Ext::TAG_OPERATION, Ext::TAG_OPERATION_DELIVER) + end + + def on_finish(span, event, _id, payload) + super + + span.resource = payload[:mailer] + span.set_tag(Ext::TAG_MAILER, payload[:mailer]) span.set_tag(Ext::TAG_MSG_ID, payload[:message_id]) - span.set_tag(Tracing::Metadata::Ext::TAG_OPERATION, Ext::TAG_OPERATION_DELIVER) - # Since email data can contain PII we disable by default # Some of these fields can be either strings or arrays, so we try to normalize # https://github.com/rails/rails/blob/18707ab17fa492eb25ad2e8f9818a320dc20b823/actionmailer/lib/action_mailer/base.rb#L742-L754 diff --git a/lib/datadog/tracing/contrib/action_mailer/events/process.rb b/lib/datadog/tracing/contrib/action_mailer/events/process.rb index 50298d9a951..e89b13d802a 100644 --- a/lib/datadog/tracing/contrib/action_mailer/events/process.rb +++ b/lib/datadog/tracing/contrib/action_mailer/events/process.rb @@ -30,10 +30,11 @@ def span_type Tracing::Metadata::Ext::HTTP::TYPE_TEMPLATE end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) super - span.type = span_type + span.resource = payload[:mailer] + span.set_tag(Ext::TAG_ACTION, payload[:action]) span.set_tag(Ext::TAG_MAILER, payload[:mailer]) diff --git a/lib/datadog/tracing/contrib/action_view/events/render_partial.rb b/lib/datadog/tracing/contrib/action_view/events/render_partial.rb index 80b473c1f82..3c6579c6a6e 100644 --- a/lib/datadog/tracing/contrib/action_view/events/render_partial.rb +++ b/lib/datadog/tracing/contrib/action_view/events/render_partial.rb @@ -27,7 +27,7 @@ def span_name Ext::SPAN_RENDER_PARTIAL end - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) span.service = configuration[:service_name] if configuration[:service_name] span.type = Tracing::Metadata::Ext::HTTP::TYPE_TEMPLATE @@ -41,10 +41,6 @@ def process(span, _event, _id, payload) # Measure service stats Contrib::Analytics.set_measured(span) - - record_exception(span, payload) - rescue StandardError => e - Datadog.logger.debug(e.message) end end end diff --git a/lib/datadog/tracing/contrib/action_view/events/render_template.rb b/lib/datadog/tracing/contrib/action_view/events/render_template.rb index 3df594bad34..0f5baaddc2b 100644 --- a/lib/datadog/tracing/contrib/action_view/events/render_template.rb +++ b/lib/datadog/tracing/contrib/action_view/events/render_template.rb @@ -27,7 +27,7 @@ def span_name Ext::SPAN_RENDER_TEMPLATE end - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) span.service = configuration[:service_name] if configuration[:service_name] span.type = Tracing::Metadata::Ext::HTTP::TYPE_TEMPLATE diff --git a/lib/datadog/tracing/contrib/active_job/events/discard.rb b/lib/datadog/tracing/contrib/active_job/events/discard.rb index 0d7c3abfe92..2a3cd8bfc7c 100644 --- a/lib/datadog/tracing/contrib/active_job/events/discard.rb +++ b/lib/datadog/tracing/contrib/active_job/events/discard.rb @@ -26,7 +26,7 @@ def span_name Ext::SPAN_DISCARD end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) span.name = span_name span.service = configuration[:service_name] if configuration[:service_name] span.resource = payload[:job].class.name diff --git a/lib/datadog/tracing/contrib/active_job/events/enqueue.rb b/lib/datadog/tracing/contrib/active_job/events/enqueue.rb index 5117d1aeac9..7ca0ca94ff0 100644 --- a/lib/datadog/tracing/contrib/active_job/events/enqueue.rb +++ b/lib/datadog/tracing/contrib/active_job/events/enqueue.rb @@ -26,7 +26,7 @@ def span_name Ext::SPAN_ENQUEUE end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) span.name = span_name span.service = configuration[:service_name] if configuration[:service_name] span.resource = payload[:job].class.name diff --git a/lib/datadog/tracing/contrib/active_job/events/enqueue_at.rb b/lib/datadog/tracing/contrib/active_job/events/enqueue_at.rb index cafe7398488..cdaf5bd9172 100644 --- a/lib/datadog/tracing/contrib/active_job/events/enqueue_at.rb +++ b/lib/datadog/tracing/contrib/active_job/events/enqueue_at.rb @@ -26,7 +26,7 @@ def span_name Ext::SPAN_ENQUEUE end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) span.name = span_name span.service = configuration[:service_name] if configuration[:service_name] span.resource = payload[:job].class.name diff --git a/lib/datadog/tracing/contrib/active_job/events/enqueue_retry.rb b/lib/datadog/tracing/contrib/active_job/events/enqueue_retry.rb index 910486b99ac..b1e62e8d878 100644 --- a/lib/datadog/tracing/contrib/active_job/events/enqueue_retry.rb +++ b/lib/datadog/tracing/contrib/active_job/events/enqueue_retry.rb @@ -26,7 +26,7 @@ def span_name Ext::SPAN_ENQUEUE_RETRY end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) span.name = span_name span.service = configuration[:service_name] if configuration[:service_name] span.resource = payload[:job].class.name diff --git a/lib/datadog/tracing/contrib/active_job/events/perform.rb b/lib/datadog/tracing/contrib/active_job/events/perform.rb index 99e781998a5..cc704c72c7b 100644 --- a/lib/datadog/tracing/contrib/active_job/events/perform.rb +++ b/lib/datadog/tracing/contrib/active_job/events/perform.rb @@ -26,7 +26,7 @@ def span_name Ext::SPAN_PERFORM end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) span.name = span_name span.service = configuration[:service_name] if configuration[:service_name] span.resource = payload[:job].class.name diff --git a/lib/datadog/tracing/contrib/active_job/events/retry_stopped.rb b/lib/datadog/tracing/contrib/active_job/events/retry_stopped.rb index 639257acd09..908a5894520 100644 --- a/lib/datadog/tracing/contrib/active_job/events/retry_stopped.rb +++ b/lib/datadog/tracing/contrib/active_job/events/retry_stopped.rb @@ -26,7 +26,7 @@ def span_name Ext::SPAN_RETRY_STOPPED end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) span.name = span_name span.service = configuration[:service_name] if configuration[:service_name] span.resource = payload[:job].class.name diff --git a/lib/datadog/tracing/contrib/active_model_serializers/events/render.rb b/lib/datadog/tracing/contrib/active_model_serializers/events/render.rb index 72f626702a0..91944c0709a 100644 --- a/lib/datadog/tracing/contrib/active_model_serializers/events/render.rb +++ b/lib/datadog/tracing/contrib/active_model_serializers/events/render.rb @@ -30,7 +30,7 @@ def span_name Ext::SPAN_RENDER end - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) span.set_tag(Tracing::Metadata::Ext::TAG_OPERATION, Ext::TAG_OPERATION_RENDER) set_common_tags(span, payload) diff --git a/lib/datadog/tracing/contrib/active_model_serializers/events/serialize.rb b/lib/datadog/tracing/contrib/active_model_serializers/events/serialize.rb index d26a833a1f2..c2c7e9f4c5b 100644 --- a/lib/datadog/tracing/contrib/active_model_serializers/events/serialize.rb +++ b/lib/datadog/tracing/contrib/active_model_serializers/events/serialize.rb @@ -32,7 +32,7 @@ def span_name Ext::SPAN_SERIALIZE end - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) span.set_tag(Tracing::Metadata::Ext::TAG_OPERATION, Ext::TAG_OPERATION_SERIALIZE) set_common_tags(span, payload) diff --git a/lib/datadog/tracing/contrib/active_record/events/instantiation.rb b/lib/datadog/tracing/contrib/active_record/events/instantiation.rb index f2b183c9f61..0d0cf07b6cc 100644 --- a/lib/datadog/tracing/contrib/active_record/events/instantiation.rb +++ b/lib/datadog/tracing/contrib/active_record/events/instantiation.rb @@ -31,7 +31,7 @@ def span_name Ext::SPAN_INSTANTIATION end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) span.resource = payload.fetch(:class_name) span.type = Ext::SPAN_TYPE_INSTANTIATION span.set_tag(Tracing::Metadata::Ext::TAG_COMPONENT, Ext::TAG_COMPONENT) diff --git a/lib/datadog/tracing/contrib/active_record/events/sql.rb b/lib/datadog/tracing/contrib/active_record/events/sql.rb index 41b4033d40e..9b9c79684b0 100644 --- a/lib/datadog/tracing/contrib/active_record/events/sql.rb +++ b/lib/datadog/tracing/contrib/active_record/events/sql.rb @@ -29,7 +29,7 @@ def span_name Ext::SPAN_SQL end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) config = Utils.connection_config(payload[:connection], payload[:connection_id]) settings = Datadog.configuration.tracing[:active_record, config] adapter_name = Contrib::Utils::Database.normalize_vendor(config[:adapter]) diff --git a/lib/datadog/tracing/contrib/active_support/notifications/event.rb b/lib/datadog/tracing/contrib/active_support/notifications/event.rb index d36e0dcf4da..efa2e78106c 100644 --- a/lib/datadog/tracing/contrib/active_support/notifications/event.rb +++ b/lib/datadog/tracing/contrib/active_support/notifications/event.rb @@ -26,11 +26,12 @@ def subscribe! # rubocop:disable Lint/UselessMethodDefinition super end - def subscription(span_name = nil, options = nil) + def subscription(span_name = nil, options = nil, on_start: nil, on_finish: nil) super( span_name || self.span_name, options || span_options, - &method(:process) + on_start: on_start, + on_finish: on_finish ) end @@ -40,7 +41,8 @@ def subscribe(pattern = nil, span_name = nil, options = nil) pattern || event_name, span_name || self.span_name, options || span_options, - &method(:process) + on_start: method(:on_start), + on_finish: method(:on_finish) ) end end @@ -62,6 +64,21 @@ def payload_exception(payload) payload[:exception_object] || payload[:exception] # Fallback for ActiveSupport < 5.0 end + + def on_start(_span, _event, _id, _payload); end + + def on_finish(span, _event, _id, payload) + record_exception(span, payload) + end + + def record_exception(span, payload) + if payload[:exception_object] + span.set_error(payload[:exception_object]) + elsif payload[:exception] + # Fallback for ActiveSupport < 5.0 + span.set_error(payload[:exception]) + end + end end end end diff --git a/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb b/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb index 7333057c67f..22ca5e6cf6a 100644 --- a/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb +++ b/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb @@ -45,16 +45,16 @@ def subscribe! end # Creates a subscription and immediately activates it. - def subscribe(pattern, span_name, options = {}, &block) - subscription(span_name, options, &block).tap do |subscription| + def subscribe(pattern, span_name, options = {}, on_start: nil, on_finish: nil) + subscription(span_name, options, on_start: on_start, on_finish: on_finish).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, options = {}, &block) - Subscription.new(span_name, options, &block).tap do |subscription| + def subscription(span_name, options = {}, on_start: nil, on_finish: nil) + Subscription.new(span_name, options, on_start: on_start, on_finish: on_finish).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 2105e5ba3c6..132aa7e4f0c 100644 --- a/lib/datadog/tracing/contrib/active_support/notifications/subscription.rb +++ b/lib/datadog/tracing/contrib/active_support/notifications/subscription.rb @@ -11,12 +11,19 @@ class Subscription :span_name, :options - def initialize(span_name, options, &block) - raise ArgumentError, 'Must be given a block!' unless block + # @param span_name [String] the operation name for the span + # @param options [Hash] options to pass during span creation + # @param on_start [Proc] a block to run when the event is fired, + # 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, options, on_start: nil, on_finish: nil) + raise ArgumentError, 'Must be given either on_start or on_finish' unless on_start || on_finish @span_name = span_name @options = options - @handler = Handler.new(&block) + @on_start = Handler.new(on_start) + @on_finish = Handler.new(on_finish) @callbacks = Callbacks.new end @@ -69,7 +76,8 @@ def unsubscribe_all protected attr_reader \ - :handler, + :on_start, + :on_finish, :callbacks def start_span(name, id, payload, start = nil) @@ -77,11 +85,15 @@ def start_span(name, id, payload, start = nil) callbacks.run(name, :before_trace, id, payload, start) # Start a trace - Tracing.trace(@span_name, **@options).tap do |span| - # Start span if time is provided - span.start(start) unless start.nil? - payload[:datadog_span] = span - end + span = Tracing.trace(@span_name, **@options) + + # Start span if time is provided + span.start(start) unless start.nil? + payload[:datadog_span] = span + + on_start.run(span, name, id, payload) + + span end def finish_span(name, id, payload, finish = nil) @@ -90,7 +102,7 @@ def finish_span(name, id, payload, finish = nil) return nil if span.nil? # Run handler for event - handler.run(span, name, id, payload) + on_finish.run(span, name, id, payload) # Finish the span span.finish(finish) @@ -109,18 +121,20 @@ def subscribers class Handler attr_reader :block - def initialize(&block) + def initialize(block) @block = block end def run(span, name, id, payload) - run!(span, name, id, payload) + run!(span, name, id, payload) if @block rescue StandardError => e Datadog.logger.debug( "ActiveSupport::Notifications handler for '#{name}' failed: #{e.class.name} #{e.message}" ) end + private + def run!(*args) @block.call(*args) end diff --git a/lib/datadog/tracing/contrib/kafka/consumer_event.rb b/lib/datadog/tracing/contrib/kafka/consumer_event.rb index 92646e6f226..d63a4ff241e 100644 --- a/lib/datadog/tracing/contrib/kafka/consumer_event.rb +++ b/lib/datadog/tracing/contrib/kafka/consumer_event.rb @@ -6,7 +6,7 @@ module Contrib module Kafka # Defines basic behaviors for an event for a consumer. module ConsumerEvent - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) super span.set_tag(Ext::TAG_GROUP, payload[:group_id]) diff --git a/lib/datadog/tracing/contrib/kafka/consumer_group_event.rb b/lib/datadog/tracing/contrib/kafka/consumer_group_event.rb index 38af322ade8..edfa13333f5 100644 --- a/lib/datadog/tracing/contrib/kafka/consumer_group_event.rb +++ b/lib/datadog/tracing/contrib/kafka/consumer_group_event.rb @@ -6,7 +6,7 @@ module Contrib module Kafka # Defines basic behaviors for an event for a consumer group. module ConsumerGroupEvent - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) super span.resource = payload[:group_id] diff --git a/lib/datadog/tracing/contrib/kafka/event.rb b/lib/datadog/tracing/contrib/kafka/event.rb index a1ecedffb46..5238fdaeea4 100644 --- a/lib/datadog/tracing/contrib/kafka/event.rb +++ b/lib/datadog/tracing/contrib/kafka/event.rb @@ -29,7 +29,7 @@ def configuration Datadog.configuration.tracing[:kafka] end - def process(span, _event, _id, payload) + def on_start(span, _event, _id, payload) span.set_tag(Tracing::Metadata::Ext::TAG_COMPONENT, Ext::TAG_COMPONENT) span.set_tag(Contrib::Ext::Messaging::TAG_SYSTEM, Ext::TAG_MESSAGING_SYSTEM) diff --git a/lib/datadog/tracing/contrib/kafka/events/connection/request.rb b/lib/datadog/tracing/contrib/kafka/events/connection/request.rb index 848ceadc1a6..9f7a34e0003 100644 --- a/lib/datadog/tracing/contrib/kafka/events/connection/request.rb +++ b/lib/datadog/tracing/contrib/kafka/events/connection/request.rb @@ -15,7 +15,9 @@ module Request EVENT_NAME = 'request.connection.kafka' - def self.process(span, _event, _id, payload) + module_function + + def on_start(span, _event, _id, payload) super span.resource = payload[:api] @@ -24,8 +26,6 @@ def self.process(span, _event, _id, payload) span.set_tag(Ext::TAG_RESPONSE_SIZE, payload[:response_size]) if payload.key?(:response_size) end - module_function - def span_name Ext::SPAN_CONNECTION_REQUEST end diff --git a/lib/datadog/tracing/contrib/kafka/events/consumer/process_batch.rb b/lib/datadog/tracing/contrib/kafka/events/consumer/process_batch.rb index 6db965ba1c3..23e2a38f0b5 100644 --- a/lib/datadog/tracing/contrib/kafka/events/consumer/process_batch.rb +++ b/lib/datadog/tracing/contrib/kafka/events/consumer/process_batch.rb @@ -17,7 +17,9 @@ module ProcessBatch EVENT_NAME = 'process_batch.consumer.kafka' - def self.process(span, _event, _id, payload) + module_function + + def on_start(span, _event, _id, payload) super span.resource = payload[:topic] @@ -31,8 +33,6 @@ def self.process(span, _event, _id, payload) span.set_tag(Ext::TAG_OFFSET_LAG, payload[:offset_lag]) if payload.key?(:offset_lag) end - module_function - def span_name Ext::SPAN_PROCESS_BATCH end diff --git a/lib/datadog/tracing/contrib/kafka/events/consumer/process_message.rb b/lib/datadog/tracing/contrib/kafka/events/consumer/process_message.rb index 5b50ad589b3..7c6fba7966a 100644 --- a/lib/datadog/tracing/contrib/kafka/events/consumer/process_message.rb +++ b/lib/datadog/tracing/contrib/kafka/events/consumer/process_message.rb @@ -17,7 +17,9 @@ module ProcessMessage EVENT_NAME = 'process_message.consumer.kafka' - def self.process(span, _event, _id, payload) + module_function + + def on_start(span, _event, _id, payload) super span.resource = payload[:topic] @@ -29,8 +31,6 @@ def self.process(span, _event, _id, payload) span.set_tag(Ext::TAG_OFFSET_LAG, payload[:offset_lag]) if payload.key?(:offset_lag) end - module_function - def span_name Ext::SPAN_PROCESS_MESSAGE end diff --git a/lib/datadog/tracing/contrib/kafka/events/consumer_group/heartbeat.rb b/lib/datadog/tracing/contrib/kafka/events/consumer_group/heartbeat.rb index 8cf99148c81..1e8c728b901 100644 --- a/lib/datadog/tracing/contrib/kafka/events/consumer_group/heartbeat.rb +++ b/lib/datadog/tracing/contrib/kafka/events/consumer_group/heartbeat.rb @@ -19,7 +19,9 @@ module Heartbeat EVENT_NAME = 'heartbeat.consumer.kafka' - def self.process(span, _event, _id, payload) + module_function + + def on_start(span, _event, _id, payload) super if payload.key?(:topic_partitions) @@ -29,8 +31,6 @@ def self.process(span, _event, _id, payload) end end - module_function - def span_name Ext::SPAN_CONSUMER_HEARTBEAT end diff --git a/lib/datadog/tracing/contrib/kafka/events/produce_operation/send_messages.rb b/lib/datadog/tracing/contrib/kafka/events/produce_operation/send_messages.rb index 850065d25f3..9de3a31aae7 100644 --- a/lib/datadog/tracing/contrib/kafka/events/produce_operation/send_messages.rb +++ b/lib/datadog/tracing/contrib/kafka/events/produce_operation/send_messages.rb @@ -15,7 +15,9 @@ module SendMessages EVENT_NAME = 'send_messages.producer.kafka' - def self.process(span, _event, _id, payload) + module_function + + def on_start(span, _event, _id, payload) super span.set_tag(Ext::TAG_MESSAGE_COUNT, payload[:message_count]) if payload.key?(:message_count) @@ -23,8 +25,6 @@ def self.process(span, _event, _id, payload) span.set_tag(Tracing::Metadata::Ext::TAG_KIND, Tracing::Metadata::Ext::SpanKind::TAG_PRODUCER) end - module_function - def span_name Ext::SPAN_SEND_MESSAGES end diff --git a/lib/datadog/tracing/contrib/kafka/events/producer/deliver_messages.rb b/lib/datadog/tracing/contrib/kafka/events/producer/deliver_messages.rb index 519c9a32a1f..f258af1b63c 100644 --- a/lib/datadog/tracing/contrib/kafka/events/producer/deliver_messages.rb +++ b/lib/datadog/tracing/contrib/kafka/events/producer/deliver_messages.rb @@ -15,7 +15,9 @@ module DeliverMessages EVENT_NAME = 'deliver_messages.producer.kafka' - def self.process(span, _event, _id, payload) + module_function + + def on_start(span, _event, _id, payload) super span.set_tag(Ext::TAG_ATTEMPTS, payload[:attempts]) if payload.key?(:attempts) @@ -26,8 +28,6 @@ def self.process(span, _event, _id, payload) span.set_tag(Tracing::Metadata::Ext::TAG_KIND, Tracing::Metadata::Ext::SpanKind::TAG_PRODUCER) end - module_function - def span_name Ext::SPAN_DELIVER_MESSAGES end diff --git a/lib/datadog/tracing/contrib/racecar/event.rb b/lib/datadog/tracing/contrib/racecar/event.rb index f1c49f99515..df15bb4bca4 100644 --- a/lib/datadog/tracing/contrib/racecar/event.rb +++ b/lib/datadog/tracing/contrib/racecar/event.rb @@ -19,7 +19,7 @@ def self.included(base) # Class methods for Racecar events. # Note, they share the same process method and before_trace method. module ClassMethods - def subscription(*args) + def subscription(*args, **kwargs) super.tap do |subscription| subscription.before_trace { ensure_clean_context! } end @@ -33,7 +33,7 @@ def configuration Datadog.configuration.tracing[:racecar] end - def process(span, event, _id, payload) + def on_start(span, event, _id, payload) span.service = configuration[:service_name] span.resource = payload[:consumer_class] 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 c9688166f2f..99497c3a093 100644 --- a/spec/datadog/tracing/contrib/active_support/notifications/event_spec.rb +++ b/spec/datadog/tracing/contrib/active_support/notifications/event_spec.rb @@ -23,6 +23,13 @@ let(:process_block) { proc { spy.call } } let(:spy) { double(:spy) } + let(:callbacks) do + { + on_start: test_class.method(:on_start), + on_finish: test_class.method(:on_finish) + } + end + describe 'class' do describe 'behavior' do describe '#subscribe!' do @@ -51,7 +58,7 @@ describe '#subscribe' do before do expect(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription).to receive(:new) - .with(test_class.span_name, test_class.span_options) + .with(test_class.span_name, test_class.span_options, **callbacks) .and_call_original end @@ -88,25 +95,20 @@ context 'when given no options' do subject(:subscription) { test_class.subscription } - before do - expect(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription).to receive(:new) - .with(test_class.span_name, test_class.span_options) - .and_call_original - end - - it { is_expected.to be_a_kind_of(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription) } - it { expect(test_class.subscriptions).to contain_exactly(subscription) } + it { expect { subscription }.to raise_error(ArgumentError) } end context 'when given options' do - subject(:subscription) { test_class.subscription(span_name, options) } + subject(:subscription) { test_class.subscription(span_name, options, on_start: on_start, on_finish: on_finish) } let(:span_name) { double('span name') } let(:options) { double('options') } + let(:on_start) { double('on_start') } + let(:on_finish) { double('on_finish') } before do expect(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription).to receive(:new) - .with(span_name, options) + .with(span_name, options, on_start: on_start, on_finish: on_finish) .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 df65f5c7260..710002adbc7 100644 --- a/spec/datadog/tracing/contrib/active_support/notifications/subscriber_spec.rb +++ b/spec/datadog/tracing/contrib/active_support/notifications/subscriber_spec.rb @@ -13,6 +13,9 @@ describe 'class' do describe 'behavior' do + let(:on_start) { double('on start') } + let(:on_finish) { double('on finish') } + describe '#subscriptions' do subject(:subscriptions) { test_class.subscriptions } @@ -26,7 +29,8 @@ :subscription, double('span name'), double('options'), - &proc {} + on_start: on_start, + on_finish: on_finish ) is_expected.to contain_exactly(subscription) @@ -87,16 +91,17 @@ end describe '#subscribe' do - subject(:subscription) { test_class.send(:subscribe, pattern, span_name, options, &block) } + subject(:subscription) do + test_class.send(:subscribe, pattern, span_name, options, on_start: on_start, on_finish: on_finish) + end let(:pattern) { double('pattern') } let(:span_name) { double('span name') } let(:options) { double('options') } - let(:block) { proc {} } before do expect(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription).to receive(:new) - .with(span_name, options) + .with(span_name, options, on_start: on_start, on_finish: on_finish) .and_call_original expect_any_instance_of(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription) @@ -109,15 +114,16 @@ end describe '#subscription' do - subject(:subscription) { test_class.send(:subscription, span_name, options, &block) } + subject(:subscription) do + test_class.send(:subscription, span_name, options, on_start: on_start, on_finish: on_finish) + end let(:span_name) { double('span name') } let(:options) { double('options') } - let(:block) { proc {} } before do expect(Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription).to receive(:new) - .with(span_name, options) + .with(span_name, options, on_start: on_start, on_finish: on_finish) .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 90376bb68bf..11e00b2e030 100644 --- a/spec/datadog/tracing/contrib/active_support/notifications/subscription_spec.rb +++ b/spec/datadog/tracing/contrib/active_support/notifications/subscription_spec.rb @@ -6,17 +6,16 @@ RSpec.describe Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription do describe 'instance' do - subject(:subscription) { described_class.new(span_name, options, &block) } + subject(:subscription) { described_class.new(span_name, options, on_start: on_start, on_finish: on_finish) } 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(:payload) { {} } - let(:block) do - proc do |span_op, name, id, payload| - spy.call(span_op, name, id, payload) - end - end - let(:spy) { double('spy') } + + let(:on_start_spy) { double('on_start_spy') } + let(:on_finish_spy) { double('on_finish_spy') } describe 'behavior' do describe '#call' do @@ -30,16 +29,22 @@ 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(spy).to receive(:call).with(span_op, name, id, payload).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 block raises an error' do - let(:block) do + context 'when on_start raises an error' do + let(:on_start) do proc do |_span_op, _name, _id, _payload| raise ArgumentError, 'Fail!' end @@ -54,6 +59,24 @@ 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 @@ -63,7 +86,10 @@ let(:id) { double('id') } let(:span_op) { double('span_op') } + before { allow(on_start_spy).to receive(:call) } + it 'returns the span operation' do + 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) end @@ -74,6 +100,7 @@ end it 'sets span operation in payload' do + 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) expect { subject }.to change { payload[:datadog_span] }.to be(span_op) end @@ -89,7 +116,7 @@ let(:payload) { { datadog_span: span_op } } it do - expect(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).and_return(span_op).ordered is_expected.to be(span_op) end @@ -105,6 +132,7 @@ shared_examples_for 'a before_trace callback' do context 'on #start' do it do + allow(on_start_spy).to receive(:call) expect(callback_spy).to receive(:call).ordered expect(Datadog::Tracing).to receive(:trace).ordered subscription.start(double('name'), double('id'), payload) @@ -146,7 +174,7 @@ let(:payload) { { datadog_span: span_op } } it do - expect(spy).to receive(:call).ordered + allow(on_finish_spy).to receive(:call) expect(span_op).to receive(:finish).ordered expect(callback_spy).to receive(:call).ordered subscription.finish(double('name'), double('id'), payload) diff --git a/spec/datadog/tracing/contrib/rails/rack_spec.rb b/spec/datadog/tracing/contrib/rails/rack_spec.rb index bfd53177063..f0b58c89231 100644 --- a/spec/datadog/tracing/contrib/rails/rack_spec.rb +++ b/spec/datadog/tracing/contrib/rails/rack_spec.rb @@ -37,11 +37,11 @@ self.view_paths = [ActionView::FixtureResolver.new( 'layouts/application.html.erb' => '<%= yield %>', - 'test/full.html.erb' => 'Test template content', + 'test/full.html.erb' => 'Test template content with type <%= Datadog::Tracing.active_span.type %>', 'test/template_with_partial.html.erb' => 'Template with <%= render "test/outer_partial" %>', 'test/partial_does_not_exist.html.erb' => '<%= render "test/no_partial_here" %>', 'test/_outer_partial.html.erb' => 'a partial inside <%= render "test/inner_partial" %>', - 'test/_inner_partial.html.erb' => 'a partial', + 'test/_inner_partial.html.erb' => 'a partial with type <%= Datadog::Tracing.active_span.type %>', 'test/error_template.html.erb' => '<%= 1/0 %>', 'test/error_partial.html.erb' => 'Oops <%= render "test/inner_error" %>', 'test/_inner_error.html.erb' => '<%= 1/0 %>' @@ -183,8 +183,8 @@ def internal_server_error expect(render_span).to be_measured end - it 'tracing does not affect response body' do - expect(response.body).to eq('Test template content') + it 'populate span fields before the template runs' do + expect(response.body).to eq('Test template content with type template') end context 'without explicit layout' do @@ -239,8 +239,8 @@ def internal_server_error .to eq('render_partial') end - it 'tracing does not affect response body' do - expect(response.body).to eq('Template with a partial inside a partial') + it 'populate span fields before the partial runs' do + expect(response.body).to eq('Template with a partial inside a partial with type template') end end From a305f6ecbc04d7d83f7c7689a2a172e498ce5af4 Mon Sep 17 00:00:00 2001 From: Marco Costa Date: Wed, 19 Jun 2024 13:31:23 -0700 Subject: [PATCH 2/3] Rename options to span_options --- .../active_support/notifications/event.rb | 8 ++++---- .../active_support/notifications/subscriber.rb | 8 ++++---- .../notifications/subscription.rb | 18 ++++++------------ .../notifications/subscription.rbs | 2 +- 4 files changed, 15 insertions(+), 21 deletions(-) diff --git a/lib/datadog/tracing/contrib/active_support/notifications/event.rb b/lib/datadog/tracing/contrib/active_support/notifications/event.rb index efa2e78106c..68381af1957 100644 --- a/lib/datadog/tracing/contrib/active_support/notifications/event.rb +++ b/lib/datadog/tracing/contrib/active_support/notifications/event.rb @@ -26,21 +26,21 @@ def subscribe! # rubocop:disable Lint/UselessMethodDefinition super end - def subscription(span_name = nil, options = nil, on_start: nil, on_finish: nil) + def subscription(span_name = nil, span_options = nil, on_start: nil, on_finish: nil) super( span_name || self.span_name, - options || span_options, + span_options || self.span_options, on_start: on_start, on_finish: on_finish ) end - def subscribe(pattern = nil, span_name = nil, options = nil) + def subscribe(pattern = nil, span_name = nil, span_options = nil) if supported? super( pattern || event_name, span_name || self.span_name, - options || span_options, + span_options || self.span_options, on_start: method(:on_start), on_finish: method(:on_finish) ) diff --git a/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb b/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb index 22ca5e6cf6a..37d12c6507a 100644 --- a/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb +++ b/lib/datadog/tracing/contrib/active_support/notifications/subscriber.rb @@ -45,16 +45,16 @@ def subscribe! end # Creates a subscription and immediately activates it. - def subscribe(pattern, span_name, options = {}, on_start: nil, on_finish: nil) - subscription(span_name, 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) + subscription(span_name, span_options, on_start: on_start, on_finish: on_finish).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, options = {}, on_start: nil, on_finish: nil) - Subscription.new(span_name, options, on_start: on_start, on_finish: on_finish).tap do |subscription| + 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| 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 132aa7e4f0c..972baf010cc 100644 --- a/lib/datadog/tracing/contrib/active_support/notifications/subscription.rb +++ b/lib/datadog/tracing/contrib/active_support/notifications/subscription.rb @@ -9,19 +9,19 @@ module Notifications class Subscription attr_accessor \ :span_name, - :options + :span_options # @param span_name [String] the operation name for the span - # @param options [Hash] options to pass during span creation + # @param span_options [Hash] span_options to pass during span creation # @param on_start [Proc] a block to run when the event is fired, # 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, options, on_start: nil, on_finish: nil) + def initialize(span_name, span_options, on_start: nil, on_finish: nil) raise ArgumentError, 'Must be given either on_start or on_finish' unless on_start || on_finish @span_name = span_name - @options = options + @span_options = span_options @on_start = Handler.new(on_start) @on_finish = Handler.new(on_finish) @callbacks = Callbacks.new @@ -85,7 +85,7 @@ def start_span(name, id, payload, start = nil) callbacks.run(name, :before_trace, id, payload, start) # Start a trace - span = Tracing.trace(@span_name, **@options) + span = Tracing.trace(@span_name, **@span_options) # Start span if time is provided span.start(start) unless start.nil? @@ -126,18 +126,12 @@ def initialize(block) end def run(span, name, id, payload) - run!(span, name, id, payload) if @block + @block.call(span, name, id, payload) if @block rescue StandardError => e Datadog.logger.debug( "ActiveSupport::Notifications handler for '#{name}' failed: #{e.class.name} #{e.message}" ) end - - private - - def run!(*args) - @block.call(*args) - end end # Wrapper for subscription callbacks diff --git a/sig/datadog/tracing/contrib/active_support/notifications/subscription.rbs b/sig/datadog/tracing/contrib/active_support/notifications/subscription.rbs index b8dfe0dca2c..3c9fbd7ff67 100644 --- a/sig/datadog/tracing/contrib/active_support/notifications/subscription.rbs +++ b/sig/datadog/tracing/contrib/active_support/notifications/subscription.rbs @@ -6,7 +6,7 @@ module Datadog class Subscription attr_accessor span_name: untyped - attr_accessor options: untyped + attr_accessor span_options: untyped def initialize: (untyped span_name, untyped options) ?{ () -> untyped } -> void def call: (untyped name, untyped start, untyped finish, untyped id, untyped payload) -> untyped From 0797c4e0045e7f3e7f3fcc3d8d23e2433585e348 Mon Sep 17 00:00:00 2001 From: Marco Costa Date: Wed, 19 Jun 2024 13:34:47 -0700 Subject: [PATCH 3/3] Document that Mailer is available late --- lib/datadog/tracing/contrib/action_mailer/events/deliver.rb | 2 +- lib/datadog/tracing/contrib/action_mailer/events/process.rb | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/lib/datadog/tracing/contrib/action_mailer/events/deliver.rb b/lib/datadog/tracing/contrib/action_mailer/events/deliver.rb index 4b72640d9d6..94d39635d62 100644 --- a/lib/datadog/tracing/contrib/action_mailer/events/deliver.rb +++ b/lib/datadog/tracing/contrib/action_mailer/events/deliver.rb @@ -39,7 +39,7 @@ def on_start(span, event, _id, payload) def on_finish(span, event, _id, payload) super - span.resource = payload[:mailer] + span.resource = payload[:mailer] # Mailer is not available at `on_start` span.set_tag(Ext::TAG_MAILER, payload[:mailer]) span.set_tag(Ext::TAG_MSG_ID, payload[:message_id]) diff --git a/lib/datadog/tracing/contrib/action_mailer/events/process.rb b/lib/datadog/tracing/contrib/action_mailer/events/process.rb index e89b13d802a..12d5dcfbe74 100644 --- a/lib/datadog/tracing/contrib/action_mailer/events/process.rb +++ b/lib/datadog/tracing/contrib/action_mailer/events/process.rb @@ -33,7 +33,7 @@ def span_type def on_start(span, event, _id, payload) super - span.resource = payload[:mailer] + span.resource = payload[:mailer] # Mailer is not available at `on_start` span.set_tag(Ext::TAG_ACTION, payload[:action]) span.set_tag(Ext::TAG_MAILER, payload[:mailer])