From 24eebe9e59a1434af66a20921644ea6def3b735a Mon Sep 17 00:00:00 2001 From: Tony Hsu Date: Wed, 25 Sep 2024 12:46:20 +0200 Subject: [PATCH 1/2] Rescue instrumentation errors --- .../contrib/active_record/events/instantiation.rb | 4 +++- lib/datadog/tracing/contrib/active_record/events/sql.rb | 4 +++- .../tracing/contrib/active_support/cache/events/cache.rb | 4 ++++ lib/datadog/tracing/contrib/aws/instrumentation.rb | 5 +++++ lib/datadog/tracing/contrib/faraday/middleware.rb | 9 +++++++++ .../tracing/contrib/httpclient/instrumentation.rb | 3 +++ lib/datadog/tracing/contrib/httprb/instrumentation.rb | 3 +++ lib/datadog/tracing/contrib/mongodb/subscribers.rb | 2 ++ lib/datadog/tracing/contrib/redis/tags.rb | 4 ++++ 9 files changed, 36 insertions(+), 2 deletions(-) diff --git a/lib/datadog/tracing/contrib/active_record/events/instantiation.rb b/lib/datadog/tracing/contrib/active_record/events/instantiation.rb index 0d0cf07b6cc..fb0d4465f53 100644 --- a/lib/datadog/tracing/contrib/active_record/events/instantiation.rb +++ b/lib/datadog/tracing/contrib/active_record/events/instantiation.rb @@ -4,6 +4,7 @@ require_relative '../../analytics' require_relative '../ext' require_relative '../event' +require_relative '../../../../core/telemetry/logger' module Datadog module Tracing @@ -48,7 +49,8 @@ def on_start(span, event, _id, payload) span.set_tag(Ext::TAG_INSTANTIATION_CLASS_NAME, payload.fetch(:class_name)) span.set_tag(Ext::TAG_INSTANTIATION_RECORD_COUNT, payload.fetch(:record_count)) rescue StandardError => e - Datadog.logger.debug(e.message) + Datadog.logger.error(e.message) + Datadog::Core::Telemetry::Logger.report(e) end end end diff --git a/lib/datadog/tracing/contrib/active_record/events/sql.rb b/lib/datadog/tracing/contrib/active_record/events/sql.rb index 1e1c1a87382..8640ac43aa9 100644 --- a/lib/datadog/tracing/contrib/active_record/events/sql.rb +++ b/lib/datadog/tracing/contrib/active_record/events/sql.rb @@ -6,6 +6,7 @@ require_relative '../ext' require_relative '../../analytics' require_relative '../../utils/database' +require_relative '../../../../core/telemetry/logger' module Datadog module Tracing @@ -68,7 +69,8 @@ def on_start(span, event, _id, payload) span.set_tag(Tracing::Metadata::Ext::NET::TAG_TARGET_HOST, config[:host]) if config[:host] span.set_tag(Tracing::Metadata::Ext::NET::TAG_TARGET_PORT, config[:port]) if config[:port] rescue StandardError => e - Datadog.logger.debug(e.message) + Datadog.logger.error(e.message) + Datadog::Core::Telemetry::Logger.report(e) 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 index 2abec4c1d26..0b98c7943ef 100644 --- a/lib/datadog/tracing/contrib/active_support/cache/events/cache.rb +++ b/lib/datadog/tracing/contrib/active_support/cache/events/cache.rb @@ -2,6 +2,7 @@ require_relative '../../ext' require_relative '../event' +require_relative '../../../../../core/telemetry/logger' module Datadog module Tracing @@ -81,6 +82,9 @@ def on_start(span, event, _id, payload) span.set_tag('EVENT', event) set_cache_key(span, key, mapping[:multi_key]) + rescue StandardError => e + Datadog.logger.error(e.message) + Datadog::Core::Telemetry::Logger.report(e) end def set_cache_key(span, key, multi_key) diff --git a/lib/datadog/tracing/contrib/aws/instrumentation.rb b/lib/datadog/tracing/contrib/aws/instrumentation.rb index 7194ef9ae01..a19ea684877 100644 --- a/lib/datadog/tracing/contrib/aws/instrumentation.rb +++ b/lib/datadog/tracing/contrib/aws/instrumentation.rb @@ -29,6 +29,7 @@ def call(context) private # rubocop:disable Metrics/AbcSize + # rubocop:disable Metrics/MethodLength def annotate!(span, context) span.service = configuration[:service_name] span.type = Tracing::Metadata::Ext::HTTP::TYPE_OUTBOUND @@ -76,7 +77,11 @@ def annotate!(span, context) span.set_tag(Tracing::Metadata::Ext::HTTP::TAG_STATUS_CODE, context.safely(:status_code)) Contrib::SpanAttributeSchema.set_peer_service!(span, Ext::PEER_SERVICE_SOURCES) + rescue StandardError => e + Datadog.logger.error(e.message) + Datadog::Core::Telemetry::Logger.report(e) end + # rubocop:enable Metrics/MethodLength # rubocop:enable Metrics/AbcSize def configuration diff --git a/lib/datadog/tracing/contrib/faraday/middleware.rb b/lib/datadog/tracing/contrib/faraday/middleware.rb index 1134fb9379a..9bdea9c364b 100644 --- a/lib/datadog/tracing/contrib/faraday/middleware.rb +++ b/lib/datadog/tracing/contrib/faraday/middleware.rb @@ -7,6 +7,7 @@ require_relative '../analytics' require_relative 'ext' require_relative '../http_annotation_helper' +require_relative '../../../core/telemetry/logger' module Datadog module Tracing @@ -37,6 +38,7 @@ def call(env) attr_reader :app + # rubocop:disable Metrics/AbcSize def annotate!(span, env, options) span.resource = resource_name(env) span.service = service_name(env[:url].host, options) @@ -75,7 +77,11 @@ def annotate!(span, env, options) ) Contrib::SpanAttributeSchema.set_peer_service!(span, Ext::PEER_SERVICE_SOURCES) + rescue StandardError => e + Datadog.logger.error(e.message) + Datadog::Core::Telemetry::Logger.report(e) end + # rubocop:enable Metrics/AbcSize def handle_response(span, env, options) span.set_error(["Error #{env[:status]}", env[:body]]) if options[:error_status_codes].include? env[:status] @@ -85,6 +91,9 @@ def handle_response(span, env, options) span.set_tags( Datadog.configuration.tracing.header_tags.response_tags(env[:response_headers]) ) + rescue StandardError => e + Datadog.logger.error(e.message) + Datadog::Core::Telemetry::Logger.report(e) end def propagate!(trace, span, env) diff --git a/lib/datadog/tracing/contrib/httpclient/instrumentation.rb b/lib/datadog/tracing/contrib/httpclient/instrumentation.rb index 5a600970870..5cbc784bf59 100644 --- a/lib/datadog/tracing/contrib/httpclient/instrumentation.rb +++ b/lib/datadog/tracing/contrib/httpclient/instrumentation.rb @@ -102,6 +102,9 @@ def annotate_span_with_response!(span, response, request_options) span.set_tags( Datadog.configuration.tracing.header_tags.response_tags(response.header) ) + rescue StandardError => e + Datadog.logger.error("error preparing span from httpclient response: #{e}, Source: #{e.backtrace}") + Datadog::Core::Telemetry::Logger.report(e) end def annotate_span_with_error!(span, error) diff --git a/lib/datadog/tracing/contrib/httprb/instrumentation.rb b/lib/datadog/tracing/contrib/httprb/instrumentation.rb index b935d3bd14b..c39916ebb4a 100644 --- a/lib/datadog/tracing/contrib/httprb/instrumentation.rb +++ b/lib/datadog/tracing/contrib/httprb/instrumentation.rb @@ -110,6 +110,9 @@ def annotate_span_with_response!(span, response, request_options) span.set_tags( Datadog.configuration.tracing.header_tags.response_tags(response.headers) ) + rescue StandardError => e + logger.error("error preparing span from http.rb response: #{e}, Source: #{e.backtrace}") + Datadog::Core::Telemetry::Logger.report(e) end def annotate_span_with_error!(span, error) diff --git a/lib/datadog/tracing/contrib/mongodb/subscribers.rb b/lib/datadog/tracing/contrib/mongodb/subscribers.rb index 06e67add3ef..fe34da1ad9e 100644 --- a/lib/datadog/tracing/contrib/mongodb/subscribers.rb +++ b/lib/datadog/tracing/contrib/mongodb/subscribers.rb @@ -70,6 +70,8 @@ def started(event) # set the resource with the quantized query span.resource = serialized_query + rescue StandardError => e + Datadog.logger.debug("error when handling MongoDB 'started' event: #{e}") end # rubocop:enable Metrics/AbcSize diff --git a/lib/datadog/tracing/contrib/redis/tags.rb b/lib/datadog/tracing/contrib/redis/tags.rb index 6e8feb49029..98de54f41a9 100644 --- a/lib/datadog/tracing/contrib/redis/tags.rb +++ b/lib/datadog/tracing/contrib/redis/tags.rb @@ -4,6 +4,7 @@ require_relative '../analytics' require_relative 'ext' require_relative '../ext' +require_relative '../../../core/telemetry/logger' module Datadog module Tracing @@ -45,6 +46,9 @@ def set_common_tags(client, span, raw_command) span.set_tag Ext::TAG_RAW_COMMAND, raw_command Contrib::SpanAttributeSchema.set_peer_service!(span, Ext::PEER_SERVICE_SOURCES) + rescue StandardError => e + Datadog.logger.error(e.message) + Datadog::Core::Telemetry::Logger.report(e) end private From 14681aa355e95c3b00c452d50841183dabf36bca Mon Sep 17 00:00:00 2001 From: Tony Hsu Date: Wed, 25 Sep 2024 15:16:17 +0200 Subject: [PATCH 2/2] Add tests --- .../active_support/cache/events/cache.rb | 2 +- .../events/instantiation_spec.rb | 32 +++++++++++++++++ .../contrib/active_record/events/sql_spec.rb | 34 +++++++++++++++++++ .../active_support/cache/events/cache_spec.rb | 20 +++++++++++ .../tracing/contrib/redis/tags_spec.rb | 24 +++++++++++++ 5 files changed, 111 insertions(+), 1 deletion(-) create mode 100644 spec/datadog/tracing/contrib/active_record/events/instantiation_spec.rb create mode 100644 spec/datadog/tracing/contrib/active_record/events/sql_spec.rb create mode 100644 spec/datadog/tracing/contrib/active_support/cache/events/cache_spec.rb create mode 100644 spec/datadog/tracing/contrib/redis/tags_spec.rb diff --git a/lib/datadog/tracing/contrib/active_support/cache/events/cache.rb b/lib/datadog/tracing/contrib/active_support/cache/events/cache.rb index 0b98c7943ef..0b8820c8fec 100644 --- a/lib/datadog/tracing/contrib/active_support/cache/events/cache.rb +++ b/lib/datadog/tracing/contrib/active_support/cache/events/cache.rb @@ -65,7 +65,7 @@ def on_start(span, event, _id, payload) key = payload[:key] store = payload[:store] - mapping = MAPPING[event] + mapping = MAPPING.fetch(event) span.service = configuration[:cache_service] span.resource = mapping[:resource] diff --git a/spec/datadog/tracing/contrib/active_record/events/instantiation_spec.rb b/spec/datadog/tracing/contrib/active_record/events/instantiation_spec.rb new file mode 100644 index 00000000000..c0a08a0ec39 --- /dev/null +++ b/spec/datadog/tracing/contrib/active_record/events/instantiation_spec.rb @@ -0,0 +1,32 @@ +require 'spec_helper' +require 'datadog/tracing/contrib/active_record/events/instantiation' +require 'datadog/tracing/span_operation' + +RSpec.describe Datadog::Tracing::Contrib::ActiveRecord::Events::Instantiation do + describe '.event_name' do + it 'returns the correct event name' do + expect(described_class.event_name).to eq('instantiation.active_record') + end + end + + describe '.span_name' do + it 'returns the correct span name' do + expect(described_class.span_name).to eq('active_record.instantiation') + end + end + + describe '.on_start' do + context 'when an error occurs' do + let(:span) { Datadog::Tracing::SpanOperation.new('fake') } + + it 'logs the error' do + expect(Datadog.logger).to receive(:error).with(/key not found/) + expect(Datadog::Core::Telemetry::Logger).to receive(:report).with(a_kind_of(StandardError)) + + expect do + described_class.on_start(span, double, double, {}) + end.not_to raise_error + end + end + end +end diff --git a/spec/datadog/tracing/contrib/active_record/events/sql_spec.rb b/spec/datadog/tracing/contrib/active_record/events/sql_spec.rb new file mode 100644 index 00000000000..7bacaac6d25 --- /dev/null +++ b/spec/datadog/tracing/contrib/active_record/events/sql_spec.rb @@ -0,0 +1,34 @@ +require 'spec_helper' +require 'datadog/tracing/contrib/active_record/events/sql' +require 'datadog/tracing/span_operation' + +require 'active_record' + +RSpec.describe Datadog::Tracing::Contrib::ActiveRecord::Events::SQL do + describe '.event_name' do + it 'returns the correct event name' do + expect(described_class.event_name).to eq('sql.active_record') + end + end + + describe '.span_name' do + it 'returns the correct span name' do + expect(described_class.span_name).to eq('active_record.sql') + end + end + + describe '.on_start' do + context 'when an error occurs' do + let(:span) { Datadog::Tracing::SpanOperation.new('fake') } + + it 'logs the error' do + expect(Datadog.logger).to receive(:error).with(/key not found/) + expect(Datadog::Core::Telemetry::Logger).to receive(:report).with(a_kind_of(StandardError)) + + expect do + described_class.on_start(span, double, double, {}) + end.not_to raise_error + end + end + end +end diff --git a/spec/datadog/tracing/contrib/active_support/cache/events/cache_spec.rb b/spec/datadog/tracing/contrib/active_support/cache/events/cache_spec.rb new file mode 100644 index 00000000000..f0df41028b5 --- /dev/null +++ b/spec/datadog/tracing/contrib/active_support/cache/events/cache_spec.rb @@ -0,0 +1,20 @@ +require 'spec_helper' +require 'datadog/tracing/contrib/active_support/cache/events/cache' +require 'datadog/tracing/span_operation' + +RSpec.describe Datadog::Tracing::Contrib::ActiveSupport::Cache::Events::Cache do + describe '.on_start' do + context 'when an error occurs' do + let(:span) { Datadog::Tracing::SpanOperation.new('fake') } + + it 'logs the error' do + expect(Datadog.logger).to receive(:error).with(/key not found/) + expect(Datadog::Core::Telemetry::Logger).to receive(:report).with(a_kind_of(StandardError)) + + expect do + described_class.on_start(span, double, double, {}) + end.not_to raise_error + end + end + end +end diff --git a/spec/datadog/tracing/contrib/redis/tags_spec.rb b/spec/datadog/tracing/contrib/redis/tags_spec.rb new file mode 100644 index 00000000000..895ab09361a --- /dev/null +++ b/spec/datadog/tracing/contrib/redis/tags_spec.rb @@ -0,0 +1,24 @@ +require 'spec_helper' +require 'datadog/tracing/contrib/redis/tags' + +require 'datadog/tracing/span_operation' + +RSpec.describe Datadog::Tracing::Contrib::Redis::Tags do + let(:client) { double('client') } + let(:span) { Datadog::Tracing::SpanOperation.new('fake') } + let(:raw_command) { 'SET key value' } + + describe '.set_common_tags' do + context 'when an error occurs' do + it 'logs the error' do + allow(client).to receive(:host).and_raise(StandardError.new('Oops...')) + expect(Datadog.logger).to receive(:error).with('Oops...') + expect(Datadog::Core::Telemetry::Logger).to receive(:report).with(a_kind_of(StandardError)) + + expect do + described_class.set_common_tags(client, span, raw_command) + end.not_to raise_error + end + end + end +end