Should OpenTelemetry::Internal::ProxyTracerProvider implement force_flush?

[richardmcmillen]

I have an a few applications that all use the same gem, the gem is instrumented with OpenTelemetry. I have the SDK configured on only some of the applications. The gem makes a call to force_flush because it does some work in a fork and then exits and I wish to make sure all spans are flushed before it exits.

I may have not set up the gem or the applications correctly but when the SDK is not configured I see the ProxyTracerProvider instance doesn't have the force_flush method.

Should the API also implement this force flush method, as a no-op? Is there some configuration I am missing?

Here is an example demonstrating this:

# frozen_string_literal: true

require 'bundler/inline'

gemfile do
  source 'https://rubygems.org'
  gem 'opentelemetry-api'
end

ENV["OTEL_LOG_LEVEL"] = "debug"
ENV["OTEL_TRACES_EXPORTER"] = "console"

puts "Configuring the API only..."

require 'opentelemetry'

begin
  tracer = OpenTelemetry.tracer_provider.tracer('TestAPI')
  puts "  tracer: #{tracer.inspect}"
  OpenTelemetry.tracer_provider.force_flush()
rescue => exception
  puts "  #{exception.class} #{exception.message}"
end

puts "-" * 80

gemfile do
  source 'https://rubygems.org'
  gem 'opentelemetry-sdk'
end

begin
  OpenTelemetry::SDK.configure

  tracer = OpenTelemetry.tracer_provider.tracer('TestSDK')
  puts "  tracer: #{tracer.inspect}"
  OpenTelemetry.tracer_provider.force_flush
rescue => exception
  puts "  #{exception.class} #{exception.message}"
end

Will result in:

Configuring the API only...
  tracer: #<OpenTelemetry::Internal::ProxyTracer:0x00007fb17385c498 @delegate=nil>
  NoMethodError undefined method `force_flush' for #<OpenTelemetry::Internal::ProxyTracerProvider:0x00007fb173866718>
--------------------------------------------------------------------------------
D, [2022-11-12T20:31:33.635141 #42320] DEBUG -- : Upgrading default proxy tracer provider to OpenTelemetry::SDK::Trace::TracerProvider
  tracer: #<OpenTelemetry::SDK::Trace::Tracer:0x00007fb17e097e00 @instrumentation_scope=#<struct OpenTelemetry::SDK::InstrumentationScope name="TestSDK", version="">, @tracer_provider=#<OpenTelemetry::SDK::Trace::TracerProvider:0x00007fb17a130c30 @mutex=#<Thread::Mutex:0x00007fb17a130a78>, @registry={#<struct OpenTelemetry::SDK::Trace::TracerProvider::Key name="TestAPI", version="">=>#<OpenTelemetry::SDK::Trace::Tracer:0x00007fb17e097ef0 @instrumentation_scope=#<struct OpenTelemetry::SDK::InstrumentationScope name="TestAPI", version="">, @tracer_provider=#<OpenTelemetry::SDK::Trace::TracerProvider:0x00007fb17a130c30 ...>>, #<struct OpenTelemetry::SDK::Trace::TracerProvider::Key name="TestSDK", version="">=>#<OpenTelemetry::SDK::Trace::Tracer:0x00007fb17e097e00 ...>}, @registry_mutex=#<Thread::Mutex:0x00007fb17a130a28>, @span_processors=[#<OpenTelemetry::SDK::Trace::Export::SimpleSpanProcessor:0x00007fb17a130fc8 @span_exporter=#<OpenTelemetry::SDK::Trace::Export::ConsoleSpanExporter:0x00007fb17a130ff0 @stopped=false>>], @span_limits=#<OpenTelemetry::SDK::Trace::SpanLimits:0x00007fb17dea1e98 @attribute_count_limit=128, @attribute_length_limit=nil, @event_count_limit=128, @link_count_limit=128, @event_attribute_count_limit=128, @event_attribute_length_limit=nil, @link_attribute_count_limit=128>, @sampler=#<OpenTelemetry::SDK::Trace::Samplers::ParentBased:0x00007fb17a130c08 @root=#<OpenTelemetry::SDK::Trace::Samplers::ConstantSampler:0x00007fb17a1904c8 @decision=:__record_and_sample__, @description="AlwaysOnSampler">, @remote_parent_sampled=#<OpenTelemetry::SDK::Trace::Samplers::ConstantSampler:0x00007fb17a1904c8 @decision=:__record_and_sample__, @description="AlwaysOnSampler">, @remote_parent_not_sampled=#<OpenTelemetry::SDK::Trace::Samplers::ConstantSampler:0x00007fb17a190310 @decision=:__drop__, @description="AlwaysOffSampler">, @local_parent_sampled=#<OpenTelemetry::SDK::Trace::Samplers::ConstantSampler:0x00007fb17a1904c8 @decision=:__record_and_sample__, @description="AlwaysOnSampler">, @local_parent_not_sampled=#<OpenTelemetry::SDK::Trace::Samplers::ConstantSampler:0x00007fb17a190310 @decision=:__drop__, @description="AlwaysOffSampler">>, @id_generator=OpenTelemetry::Trace, @stopped=false, @resource=#<OpenTelemetry::SDK::Resources::Resource:0x00007fb17a132828 @attributes={"service.name"=>"unknown_service", "process.pid"=>42320, "process.command"=>"otel-force-flush-test.rb", "process.runtime.name"=>"ruby", "process.runtime.version"=>"2.7.5", "process.runtime.description"=>"ruby 2.7.5p203 (2021-11-24 revision f69aeb8314) [x86_64-darwin21]", "telemetry.sdk.name"=>"opentelemetry", "telemetry.sdk.language"=>"ruby", "telemetry.sdk.version"=>"1.2.0"}>>>

[richardmcmillen]

Some more information, the gem has its instrumentation inline, it is never installed like the instrumentation I can see in opentelemetry-ruby-contrib. So the force_flush code path is hit regardless of whether the SDK is used. I understand how I could overcome this issue by allowing the instrumentation to be installed so this code path isn't hit when the SDK isn't configured, but I was under the impression the API should mirror the SDK.

[richardmcmillen]

Before opening a PR to the spec I will do some hunting first, I found this issue which adds the shutdown method: open-telemetry/opentelemetry-specification#1073

Then later someone adds the force_flush method: open-telemetry/opentelemetry-specification#1451

In the former you can see discussion about whether or not the API needs the shutdown method, it was decided no, but the same discussion did not happen on the force_flush PR.

When I get time I will open a PR with a proposal to add at least the force_flush method to the API spec.

[richardmcmillen]

PR to the spec was made here: open-telemetry/opentelemetry-specification#2944

[ahayworth]

the code may rely on SDK methods and the test suite wouldn't catch this

Seems like that is precisely what happened. 🤦

Honestly, I'm surprised the API spec doesn't have force_flush or shutdown defined; but perhaps the authors initially thought those were SDK-only concerns. But I think it's on the boundary between API and SDK concerns, personally: normally instrumentation does not need to ensure that its spans are flushed, but in some instances (forked background jobs!) it is a very nice user convenience.

Part of me suspects that from a specification perspective, the answer would be "users of the SDK must ensure that their tracers flush their buffers before shutdown", but as someone who cares about it Just Working ™️ that's not a fantastic-feeling answer in my book. But I await the outcome of the spec issue, we should see what others say.

---

As far as fixing this today, we could take one of these paths:

1. Just remove the force_flush bits. It's not amazing to remove useful functionality, but on the other hand "it wasn't compliant with the spec" is a valid reason to do so. We could document that users should force_flush or shutdown at an appropriate place in their application.
2. Detect within the instrumentation if we can call force_flush:

OpenTelemetry.tracer_provider.force_flush if otel_config[:force_flush] && OpenTelemetry.tracer_provider.respond_to?(:force_flush)

Any preferences? Personally I lean a little towards option 2 just so we can keep the functionality, but I don't feel really strongly either way.

[richardmcmillen]

Option 2 is what I ended up doing for my own internal instrumentation but I do hope that we get a satisfying outcome from the spec PR and that the API can be updated to have force_flush.

From my understanding, due to how the instrumentation works in opentelemetry-ruby-contrib, the OpenTelemetry.tracer_provider.force_flush code path can only ever be hit when the SDK is installed and the instrumentation was selected for the SDK config. So for these instances the impact is more academic than anything else I think.

It might be possible to hit this code path if you are installing the instrumentation yourself not through the OpenTelemetry SDK but I can't imagine there are many folks doing that.

So I don't see any immediate pressing need to update the opentelemetry-ruby-contrib repo unless you feel there is, I'm interested to see what will come out of the spec issue.

[ahayworth]

Right, that makes sense - so I will not rush on fixing it up here or anything. I too am interested to see what comes of the spec discussion. 😄

[richardmcmillen]

I'd like to discuss how end users could ensure spans are flushed when the API does not have the force flush method.

Given the following:

• Some OSS job worker
• Tracing for the OSS
• End user application

Example code for these below.

If the force flush does not become part of the API how can end users actually ensure that this is the behaviour they get?

Some options I can think of:

• Write their own patch code and call the force flush method. That sounds a pretty horrible experience.
• Instrumentation accepts a config option, something responding to call, so that end users can pass in a -> { OpenTelemetry.tracer_provider.force_flush } or whatever they want.
• Use some span processor that inspects all spans as they pass through and optionally force flushing, as pointed out here: Add ForceFlush to the TracerProvider Trace API specification opentelemetry-specification#2944 (comment) (are span processors currently compose-able?)
• Break convention and test for the method on the trace provider OpenTelemetry.tracer_provider.force_flush if OpenTelemetry.tracer_provider.respond_to?(:force_flush)

Any other ideas or comments on this?

require 'bundler/inline'
require 'securerandom'

gemfile do
  source 'https://rubygems.org'
  gem 'opentelemetry-api', require: false
  gem 'opentelemetry-sdk', require: false
end

ENV["OTEL_LOG_LEVEL"] = "debug"
ENV["OTEL_TRACES_EXPORTER"] = "console"

# Example OSS library that applications depend on ------------------------------
module OssLibraryCode
  require 'opentelemetry'

  module Runner
    def self.work
      puts "Forking work"
      fork do
        do_work(SecureRandom.uuid)
      end
    end

    def self.do_work(name)
      puts "  doing work - #{name}"
    end
  end
end

# OpenTelemetry community instrumentation --------------------------------------
module OpenTelemetry::RunnerPatch
  TRACER = OpenTelemetry.tracer_provider.tracer('OpenTelemetry::RunnerTracing')

  def self.prepended(base)
    class << base
      prepend ClassMethods
    end
  end

  module ClassMethods
    def do_work(name)
      TRACER.in_span("work: #{name}") do
        super
      end
      # If .force_flush was part of the API
      # OpenTelemetry.tracer_provider.force_flush
    end
  end
end
OssLibraryCode::Runner.prepend(OpenTelemetry::RunnerPatch)

# End user application ---------------------------------------------------------
module EndUserApplication
  require 'opentelemetry-sdk'
  OpenTelemetry::SDK.configure

  def self.start
    OssLibraryCode::Runner.work
  end
end

EndUserApplication.start

[ahayworth]

I really like @reyang's AutoFlushActivityProcessor suggestion; that would allow users who desire the behavior to configure it for all instrumentation in one go.