Getting "failed to install" on numerous OpenTelemetry Instrumentations

[3ygun]

Hello,

I followed the Getting Started page mapping each direction into my Ruby on Rails application. However, when I boot the rails service I get the following (I'm using customized c.uses to avoid noise see the config below):

D, [2021-12-02T19:50:30.196618 #10] DEBUG -- : Upgrading default proxy tracer provider to OpenTelemetry::SDK::Trace::TracerProvider
W, [2021-12-02T19:50:30.196870 #10]  WARN -- : Instrumentation: OpenTelemetry::Instrumentation::ActionPack failed to install
W, [2021-12-02T19:50:30.196947 #10]  WARN -- : Instrumentation: OpenTelemetry::Instrumentation::ActionView failed to install
W, [2021-12-02T19:50:30.197015 #10]  WARN -- : Instrumentation: OpenTelemetry::Instrumentation::ActiveJob failed to install
W, [2021-12-02T19:50:30.197151 #10]  WARN -- : Instrumentation: OpenTelemetry::Instrumentation::ActiveModelSerializers failed to install
W, [2021-12-02T19:50:30.197301 #10]  WARN -- : Instrumentation: OpenTelemetry::Instrumentation::ActiveRecord failed to install
I, [2021-12-02T19:50:30.198297 #10]  INFO -- : Instrumentation: OpenTelemetry::Instrumentation::ConcurrentRuby was successfully installed
I, [2021-12-02T19:50:30.199680 #10]  INFO -- : Instrumentation: OpenTelemetry::Instrumentation::Dalli was successfully installed
W, [2021-12-02T19:50:30.199892 #10]  WARN -- : Instrumentation: OpenTelemetry::Instrumentation::HttpClient failed to install
I, [2021-12-02T19:50:30.201298 #10]  INFO -- : Instrumentation: OpenTelemetry::Instrumentation::Mysql2 was successfully installed
I, [2021-12-02T19:50:30.203433 #10]  INFO -- : Instrumentation: OpenTelemetry::Instrumentation::Rack was successfully installed
W, [2021-12-02T19:50:30.203653 #10]  WARN -- : Instrumentation: OpenTelemetry::Instrumentation::Rails failed to install
I, [2021-12-02T19:50:30.204584 #10]  INFO -- : Instrumentation: OpenTelemetry::Instrumentation::Redis was successfully installed
W, [2021-12-02T19:50:30.204806 #10]  WARN -- : Instrumentation: OpenTelemetry::Instrumentation::Sidekiq failed to install
I, [2021-12-02T19:50:30.204934 #10]  INFO -- : Instrumentation: OpenTelemetry::Instrumentation::Sinatra was successfully installed

Thus I can see some of the traces (redis, mysql, etc.) in Jaeger but not the ones from the core Rails glue of the application.
I've tried to get more information from the loggers as detailed in #966 (see the error_handler below) but I'm having no luck getting logs beyond the:

WARN -- : Instrumentation: OpenTelemetry::Instrumentation::Rails failed to install

Using rails 5.0.7.2

My config/initializers/opentelemetry.rb is:

require 'opentelemetry/sdk'
require 'opentelemetry/exporter/otlp'

OpenTelemetry::SDK.configure do |c|
  updox_otel_logger = Logger.new(STDOUT)
  OpenTelemetry.error_handler = lambda do |exception: nil, message: nil|
    updox_otel_logger.error "OpenTelemetry error: #{message}"
    updox_otel_logger.error exception
  end

  c.service_name = 'PartnerPortal'
  c.use 'OpenTelemetry::Instrumentation::ActionPack'
  c.use 'OpenTelemetry::Instrumentation::ActionView'
  c.use 'OpenTelemetry::Instrumentation::ActiveJob'
  c.use 'OpenTelemetry::Instrumentation::ActiveModelSerializers'
  c.use 'OpenTelemetry::Instrumentation::ActiveRecord'
  c.use 'OpenTelemetry::Instrumentation::ConcurrentRuby'
  c.use 'OpenTelemetry::Instrumentation::Dalli'
  c.use 'OpenTelemetry::Instrumentation::HttpClient'
  c.use 'OpenTelemetry::Instrumentation::Mysql2'
  c.use 'OpenTelemetry::Instrumentation::Rack'
  c.use 'OpenTelemetry::Instrumentation::Rails'
  c.use 'OpenTelemetry::Instrumentation::Redis'
  c.use 'OpenTelemetry::Instrumentation::Sidekiq'
  c.use 'OpenTelemetry::Instrumentation::Sinatra'
  # Avoiding use_all to isolate error messages
end

My Gemfile section for this is:

# Telemetry
gem 'opentelemetry-sdk', '~> 1.0.1'
gem 'opentelemetry-exporter-otlp', '~> 0.20.6'
gem 'opentelemetry-instrumentation-all', '~> 0.21.3'

The server is started with the following script:

#!/bin/bash

# Run database migrations.
bin/rake db:migrate --trace RAILS_ENV=docker

echo ''
echo 'Finished DB migration. Starting server...'
echo ''

# Start server.
bundle exec rails server -e docker -b 0.0.0.0 -p ${PORT}

And the OpenTracing logs listed above are getting triggered by bin/rake db:migrate ... instead of the bundle exec ...

[arielvalentin]

👋🏼 @3ygun It looks like you are using a version of Rails (5.0.2) that is now EOL. The minimum version OTEL Ruby Auto-Instrumentation will support is 5.2

Take a look at this appraisal file to see all supported versions:

https://github.com/open-telemetry/opentelemetry-ruby/blob/main/instrumentation/rails/Appraisals

[3ygun]

@arielvalentin Thanks for the information on that. I didn't know there was an "Appraisals" file. I had looked for the minimal rails version on the https://rubygems.org/gems/opentelemetry-instrumentation-rails page which shows as rails >= 0 which obviously I meet with an EOL version BUT not with the Appraisals file.

Either way that's an actionable next step for me to upgrade our rails version if possible.

[3ygun]

Based on your and @robertlaurin 's answers the versions that I have present in the application are probably the issue and I'll open another discussion if that isn't the case.

[arielvalentin]

Thank you for the feedback. We need to update our documentation to make it easier for folks to reason about version compatibility but I agree with you that our gem specifications could be more helpful in this regard.

cc: @ericmustin @robertlaurin #1025

[robertlaurin]

Hey,

Sharing some references to see if we can understand what is going wrong here together.

Those failure messages are from what I'll call "soft failures"

opentelemetry-ruby/instrumentation/base/lib/opentelemetry/instrumentation/registry.rb

Lines 77 to 85 in d397e1f

	def install_instrumentation(instrumentation, config)
	if instrumentation.install(config)
	OpenTelemetry.logger.info "Instrumentation: #{instrumentation.name} was successfully installed"
	else
	OpenTelemetry.logger.warn "Instrumentation: #{instrumentation.name} failed to install"
	end
	rescue => e # rubocop:disable Style/RescueStandardError
	OpenTelemetry.handle_error(exception: e, message: "Instrumentation: #{instrumentation.name} unhandled exception during install: #{e.backtrace}")
	end

That means during the install process failed somewhere here

opentelemetry-ruby/instrumentation/base/lib/opentelemetry/instrumentation/base.rb

Lines 209 to 222 in d397e1f

	# Install instrumentation with the given config. The present? and compatible?
	# will be run first, and install will return false if either fail. Will
	# return true if install was completed successfully.
	#
	# @param [Hash] config The config for this instrumentation
	def install(config = {})
	return true if installed?
	return false unless installable?(config)
	@config = config_options(config)
	instance_exec(@config, &@install_blk)
	@tracer = OpenTelemetry.tracer_provider.tracer(name, version)
	@installed = true
	end

So using Rails as an example failure that means defined?(::Rails) evaluated to false or gem_version >= MINIMUM_VERSION evaluated to false

opentelemetry-ruby/instrumentation/rails/lib/opentelemetry/instrumentation/rails/instrumentation.rb

Lines 14 to 22 in d397e1f

	class Instrumentation < OpenTelemetry::Instrumentation::Base
	MINIMUM_VERSION = Gem::Version.new('5.2.0')
	# This gem requires the instrumentantion gems for the different
	# components of Rails, as a result it does not have any explicit
	# work to do in the install step.
	install { true }
	present { defined?(::Rails) }
	compatible { gem_version >= MINIMUM_VERSION }

I see that you're using Using rails 5.0.7.2 so that means it would fail to install. The other gems are quite possibly failing for other similar checks.

[3ygun]

Thanks for the detailed answer! Makes sense. Is there a reason that the error message is so basic even for something that re-portability ("gem version too old!") doesn't get logged to the user?

[robertlaurin]

There's no particular reason for it being so generic. I suppose we just haven't had an ask for it yet. I'll look at adding a bit more details for the various failure modes. However because the present and compatible blocks accept arbitrary code it will still be at the coarse level of "failed due to compatibility check" or "failed due to present check".

[grvm]

As a workaround for evaluation purposes, this helped me install everything & get it working for Rails 5.1. Has been working properly since the last 24 hours.

Update your initializer to include the following

module OpenTelemetry
  module Instrumentation
    Rails::Instrumentation::MINIMUM_VERSION = Gem::Version.new('5.1.0')
    ActiveRecord::Instrumentation::MINIMUM_VERSION = Gem::Version.new('5.1.0')
    ActionPack::Instrumentation::MINIMUM_VERSION = Gem::Version.new('5.1.0')
    ActionView::Instrumentation::MINIMUM_VERSION = Gem::Version.new('5.1.0')
  end
end

[ahayworth]

This will indeed allow the install to proceed - just be aware that we do not support those versions and make no guarantees about behavior or performance in this case. ❤️

[grvm]

Yup, learned it the hard way. Things completely broke, basically the ActiveRecord save! method

[ahayworth]

Oh no! I'm sorry to hear that, I was hoping for more success for you. ❤️