From e9428ca553925b2ab564821dc851e0b13d146a68 Mon Sep 17 00:00:00 2001 From: Yohei Kitamura <3087402+yoheyk@users.noreply.github.com> Date: Thu, 21 Mar 2024 10:47:57 -0400 Subject: [PATCH 1/5] fix: Update `untraced` to suppress logging "Calling finish on an ended Span" warnings --- sdk/lib/opentelemetry/sdk/trace/tracer.rb | 2 -- sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb | 2 +- 2 files changed, 1 insertion(+), 3 deletions(-) diff --git a/sdk/lib/opentelemetry/sdk/trace/tracer.rb b/sdk/lib/opentelemetry/sdk/trace/tracer.rb index 4a9ab340fb..1224b989ad 100644 --- a/sdk/lib/opentelemetry/sdk/trace/tracer.rb +++ b/sdk/lib/opentelemetry/sdk/trace/tracer.rb @@ -29,8 +29,6 @@ def start_root_span(name, attributes: nil, links: nil, start_timestamp: nil, kin def start_span(name, with_parent: nil, attributes: nil, links: nil, start_timestamp: nil, kind: nil) with_parent ||= Context.current - return super(name, with_parent: with_parent, attributes: attributes, links: links, start_timestamp: start_timestamp, kind: kind) if Common::Utilities.untraced?(with_parent) - name ||= 'empty' kind ||= :internal diff --git a/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb b/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb index 10a8ed8aea..18d2eae4c1 100644 --- a/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb +++ b/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb @@ -138,7 +138,7 @@ def internal_start_span(name, kind, attributes, links, start_timestamp, parent_c trace_id ||= @id_generator.generate_trace_id result = @sampler.should_sample?(trace_id: trace_id, parent_context: parent_context, links: links, name: name, kind: kind, attributes: attributes) span_id = @id_generator.generate_span_id - if result.recording? && !@stopped + if !OpenTelemetry::Common::Utilities.untraced?(parent_context) && result.recording? && !@stopped trace_flags = result.sampled? ? OpenTelemetry::Trace::TraceFlags::SAMPLED : OpenTelemetry::Trace::TraceFlags::DEFAULT context = OpenTelemetry::Trace::SpanContext.new(trace_id: trace_id, span_id: span_id, trace_flags: trace_flags, tracestate: result.tracestate) attributes = attributes&.merge(result.attributes) || result.attributes.dup From 108bde455a3425f4692eb46ded0e4e0d2df1d92b Mon Sep 17 00:00:00 2001 From: Yohei Kitamura <3087402+yoheyk@users.noreply.github.com> Date: Tue, 9 Apr 2024 16:00:57 -0400 Subject: [PATCH 2/5] add tests for untraced --- .../opentelemetry/sdk/trace/tracer_test.rb | 23 +++++++++++++++++++ 1 file changed, 23 insertions(+) diff --git a/sdk/test/opentelemetry/sdk/trace/tracer_test.rb b/sdk/test/opentelemetry/sdk/trace/tracer_test.rb index 2ced763dd6..67d5485562 100644 --- a/sdk/test/opentelemetry/sdk/trace/tracer_test.rb +++ b/sdk/test/opentelemetry/sdk/trace/tracer_test.rb @@ -329,5 +329,28 @@ _(span.status.code).must_equal(OpenTelemetry::Trace::Status::ERROR) _(span.status.description).must_equal('Unhandled exception of type: RuntimeError') end + + it 'yields a no-op span within an untraced block' do + tracer_provider.sampler = Samplers::ALWAYS_ON + tracer.in_span('root') do + OpenTelemetry::Common::Utilities.untraced do + tracer.in_span('op') do |span| + _(span).must_be_instance_of(OpenTelemetry::Trace::Span) + _(span.context.trace_flags).wont_be :sampled? + _(span).wont_be :recording? + end + end + end + end + + it 'does not log "Calling finish on an ended Span" warnings' do + tracer_provider.sampler = Samplers::ALWAYS_ON + OpenTelemetry::TestHelpers.with_test_logger do |log_stream| + tracer.in_span('root') do + OpenTelemetry::Common::Utilities.untraced { tracer.in_span('op') {} } + end + _(log_stream.string).wont_include 'Calling finish on an ended Span' + end + end end end From 23e2e86bdf10af5fcf3a1ea9cc0ae29d11c466bf Mon Sep 17 00:00:00 2001 From: Yohei Kitamura <3087402+yoheyk@users.noreply.github.com> Date: Tue, 9 Apr 2024 16:07:50 -0400 Subject: [PATCH 3/5] disable Metrics/PerceivedComplexity in TracerProvider#internal_start_span --- sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb b/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb index 18d2eae4c1..00ec265b7b 100644 --- a/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb +++ b/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb @@ -126,7 +126,7 @@ def add_span_processor(span_processor) end # @api private - def internal_start_span(name, kind, attributes, links, start_timestamp, parent_context, instrumentation_scope) # rubocop:disable Metrics/MethodLength + def internal_start_span(name, kind, attributes, links, start_timestamp, parent_context, instrumentation_scope) # rubocop:disable Metrics/MethodLength, Metrics/PerceivedComplexity parent_span = OpenTelemetry::Trace.current_span(parent_context) parent_span_context = parent_span.context From 96ac5f6f0c1747d233bef432274e92ba398bd48f Mon Sep 17 00:00:00 2001 From: Yohei Kitamura <3087402+yoheyk@users.noreply.github.com> Date: Wed, 10 Apr 2024 09:25:54 -0400 Subject: [PATCH 4/5] remove setting ALWAYS_ON from test cases --- sdk/test/opentelemetry/sdk/trace/tracer_test.rb | 2 -- 1 file changed, 2 deletions(-) diff --git a/sdk/test/opentelemetry/sdk/trace/tracer_test.rb b/sdk/test/opentelemetry/sdk/trace/tracer_test.rb index 67d5485562..949753fda8 100644 --- a/sdk/test/opentelemetry/sdk/trace/tracer_test.rb +++ b/sdk/test/opentelemetry/sdk/trace/tracer_test.rb @@ -331,7 +331,6 @@ end it 'yields a no-op span within an untraced block' do - tracer_provider.sampler = Samplers::ALWAYS_ON tracer.in_span('root') do OpenTelemetry::Common::Utilities.untraced do tracer.in_span('op') do |span| @@ -344,7 +343,6 @@ end it 'does not log "Calling finish on an ended Span" warnings' do - tracer_provider.sampler = Samplers::ALWAYS_ON OpenTelemetry::TestHelpers.with_test_logger do |log_stream| tracer.in_span('root') do OpenTelemetry::Common::Utilities.untraced { tracer.in_span('op') {} } From 5f9b4a282039442088e5f6150a3273a6ee4ec0da Mon Sep 17 00:00:00 2001 From: Yohei Kitamura <3087402+yoheyk@users.noreply.github.com> Date: Thu, 18 Apr 2024 09:27:02 -0400 Subject: [PATCH 5/5] return a non-recording span without calling @sampler.should_sample --- sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb | 11 ++++++++--- sdk/test/opentelemetry/sdk/trace/tracer_test.rb | 4 +++- 2 files changed, 11 insertions(+), 4 deletions(-) diff --git a/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb b/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb index 00ec265b7b..3569451635 100644 --- a/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb +++ b/sdk/lib/opentelemetry/sdk/trace/tracer_provider.rb @@ -126,7 +126,7 @@ def add_span_processor(span_processor) end # @api private - def internal_start_span(name, kind, attributes, links, start_timestamp, parent_context, instrumentation_scope) # rubocop:disable Metrics/MethodLength, Metrics/PerceivedComplexity + def internal_start_span(name, kind, attributes, links, start_timestamp, parent_context, instrumentation_scope) # rubocop:disable Metrics/CyclomaticComplexity, Metrics/MethodLength, Metrics/PerceivedComplexity parent_span = OpenTelemetry::Trace.current_span(parent_context) parent_span_context = parent_span.context @@ -134,11 +134,16 @@ def internal_start_span(name, kind, attributes, links, start_timestamp, parent_c parent_span_id = parent_span_context.span_id trace_id = parent_span_context.trace_id end - trace_id ||= @id_generator.generate_trace_id + + if OpenTelemetry::Common::Utilities.untraced?(parent_context) + span_id = parent_span_id || @id_generator.generate_span_id + return OpenTelemetry::Trace.non_recording_span(OpenTelemetry::Trace::SpanContext.new(trace_id: trace_id, span_id: span_id)) + end + result = @sampler.should_sample?(trace_id: trace_id, parent_context: parent_context, links: links, name: name, kind: kind, attributes: attributes) span_id = @id_generator.generate_span_id - if !OpenTelemetry::Common::Utilities.untraced?(parent_context) && result.recording? && !@stopped + if result.recording? && !@stopped trace_flags = result.sampled? ? OpenTelemetry::Trace::TraceFlags::SAMPLED : OpenTelemetry::Trace::TraceFlags::DEFAULT context = OpenTelemetry::Trace::SpanContext.new(trace_id: trace_id, span_id: span_id, trace_flags: trace_flags, tracestate: result.tracestate) attributes = attributes&.merge(result.attributes) || result.attributes.dup diff --git a/sdk/test/opentelemetry/sdk/trace/tracer_test.rb b/sdk/test/opentelemetry/sdk/trace/tracer_test.rb index 949753fda8..e5488d689b 100644 --- a/sdk/test/opentelemetry/sdk/trace/tracer_test.rb +++ b/sdk/test/opentelemetry/sdk/trace/tracer_test.rb @@ -332,9 +332,11 @@ it 'yields a no-op span within an untraced block' do tracer.in_span('root') do + span_id = OpenTelemetry::Trace.current_span.context.span_id OpenTelemetry::Common::Utilities.untraced do tracer.in_span('op') do |span| _(span).must_be_instance_of(OpenTelemetry::Trace::Span) + _(span.context.span_id).must_equal span_id _(span.context.trace_flags).wont_be :sampled? _(span).wont_be :recording? end @@ -342,7 +344,7 @@ end end - it 'does not log "Calling finish on an ended Span" warnings' do + it 'does not log "Calling finish on an ended Span" warnings when untraced? is called' do OpenTelemetry::TestHelpers.with_test_logger do |log_stream| tracer.in_span('root') do OpenTelemetry::Common::Utilities.untraced { tracer.in_span('op') {} }