From 3b8ec5182c915e5a3be3bc5ce0baf4e91182d2fe Mon Sep 17 00:00:00 2001 From: Bruno Facca Date: Wed, 22 Nov 2023 19:00:14 +0000 Subject: [PATCH] fix: Update `Net::HTTP` instrumentation to no-op on untraced contexts (#722) * chore: Add rspec-mocks development dependency * fix: Net::HTTP instrumentation no-op on untraced context Update Net::HTTP instrumentation to no-op on HTTP requests within untraced contexts. Prevents the logging of "called finish on an ended Span" messages. Example scenario: The Resque instrumentation can be configured to call `OpenTelemetry::SDK::TraceProvider#force_flush` at the end of each job. That causes the batch span processor to immediately send everything it has to the OTLP exporter. The exporter then marks the HTTP request used to send the data to the APM server as "untraced", by adding an `untraced` key to the context and setting it to `true`. Before this commit, the `Net::HTTP` instrumentation did not check for the `untraced` flag. So it would try set attributes and call `finish` on a span that was not recording, creating one "called finish on an ended Span" log entry for each batch of exported spans. On a large application, that results in millions of those log entries per minute. --------- Co-authored-by: Ariel Valentin --- .../net/http/patches/instrumentation.rb | 8 ++++++ ...telemetry-instrumentation-net_http.gemspec | 1 + .../net/http/instrumentation_test.rb | 28 +++++++++++++++++++ instrumentation/net_http/test/test_helper.rb | 1 + 4 files changed, 38 insertions(+) diff --git a/instrumentation/net_http/lib/opentelemetry/instrumentation/net/http/patches/instrumentation.rb b/instrumentation/net_http/lib/opentelemetry/instrumentation/net/http/patches/instrumentation.rb index 32a67122c..ba64b247d 100644 --- a/instrumentation/net_http/lib/opentelemetry/instrumentation/net/http/patches/instrumentation.rb +++ b/instrumentation/net_http/lib/opentelemetry/instrumentation/net/http/patches/instrumentation.rb @@ -86,12 +86,20 @@ def tracer end def untraced? + untraced_context? || untraced_host? + end + + def untraced_host? return true if Net::HTTP::Instrumentation.instance.config[:untraced_hosts]&.any? do |host| host.is_a?(Regexp) ? host.match?(@address) : host == @address end false end + + def untraced_context? + OpenTelemetry::Common::Utilities.untraced? + end end end end diff --git a/instrumentation/net_http/opentelemetry-instrumentation-net_http.gemspec b/instrumentation/net_http/opentelemetry-instrumentation-net_http.gemspec index d61af1b88..8a4f27c5e 100644 --- a/instrumentation/net_http/opentelemetry-instrumentation-net_http.gemspec +++ b/instrumentation/net_http/opentelemetry-instrumentation-net_http.gemspec @@ -34,6 +34,7 @@ Gem::Specification.new do |spec| spec.add_development_dependency 'opentelemetry-sdk', '~> 1.1' spec.add_development_dependency 'opentelemetry-test-helpers', '~> 0.3' spec.add_development_dependency 'rake', '~> 13.0.1' + spec.add_development_dependency 'rspec-mocks' spec.add_development_dependency 'rubocop', '~> 1.56.1' spec.add_development_dependency 'simplecov', '~> 0.17.1' spec.add_development_dependency 'webmock', '~> 3.19' diff --git a/instrumentation/net_http/test/opentelemetry/instrumentation/net/http/instrumentation_test.rb b/instrumentation/net_http/test/opentelemetry/instrumentation/net/http/instrumentation_test.rb index 2ab764299..fb4d61a92 100644 --- a/instrumentation/net_http/test/opentelemetry/instrumentation/net/http/instrumentation_test.rb +++ b/instrumentation/net_http/test/opentelemetry/instrumentation/net/http/instrumentation_test.rb @@ -178,6 +178,34 @@ _(span.attributes['net.peer.port']).must_equal(80) end end + + describe 'untraced context' do + it 'no-ops on #request' do + # Calling `tracer.in_span` within an untraced context causes the logging of "called + # finish on an ended Span" messages. To avoid log noise, the instrumentation must + # no-op (i.e., not call `tracer.in_span`) when the context is untraced. + expect(instrumentation.tracer).not_to receive(:in_span) + + OpenTelemetry::Common::Utilities.untraced do + Net::HTTP.get('example.com', '/body') + end + + _(exporter.finished_spans.size).must_equal 0 + end + + it 'no-ops on #connect' do + expect(instrumentation.tracer).not_to receive(:in_span) + + OpenTelemetry::Common::Utilities.untraced do + uri = URI.parse('http://example.com/body') + http = Net::HTTP.new(uri.host, uri.port) + http.send(:connect) + http.send(:do_finish) + end + + _(exporter.finished_spans.size).must_equal 0 + end + end end describe '#connect' do diff --git a/instrumentation/net_http/test/test_helper.rb b/instrumentation/net_http/test/test_helper.rb index d617b91c2..921a7e11c 100644 --- a/instrumentation/net_http/test/test_helper.rb +++ b/instrumentation/net_http/test/test_helper.rb @@ -9,6 +9,7 @@ Bundler.require(:default, :development, :test) require 'minitest/autorun' +require 'rspec/mocks/minitest_integration' require 'webmock/minitest' # global opentelemetry-sdk setup: