diff --git a/Gemfile b/Gemfile index 2018f1c81cd..1673f242f3e 100644 --- a/Gemfile +++ b/Gemfile @@ -68,6 +68,19 @@ gem 'fog-openstack' gem 'cf-uaa-lib', '~> 4.0.4' gem 'vcap-concurrency', git: 'https://github.com/cloudfoundry/vcap-concurrency.git', ref: '2a5b0179' +gem 'opentelemetry-exporter-otlp', '~> 0.26.1' +gem 'opentelemetry-instrumentation-delayed_job', '~> 0.22.1' +gem 'opentelemetry-instrumentation-http_client', '~> 0.22.3' +gem 'opentelemetry-instrumentation-mysql2', '~> 0.27.0' +gem 'opentelemetry-instrumentation-net_http', '~> 0.22.4' +gem 'opentelemetry-instrumentation-pg', '~> 0.27.1' +gem 'opentelemetry-instrumentation-rake', '~> 0.2.1' +gem 'opentelemetry-instrumentation-redis', '~> 0.25.3' +gem 'opentelemetry-propagator-b3' +gem 'opentelemetry-propagator-jaeger', '~> 0.21.0' +gem 'opentelemetry-propagator-xray', '~> 0.22.1' +gem 'opentelemetry-sdk', '~> 1.3' + group :db do gem 'mysql2', '~> 0.5.6' gem 'pg' diff --git a/Gemfile.lock b/Gemfile.lock index 1ec0bdd54ce..b42ae79c0ce 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -351,6 +351,66 @@ GEM oj (3.16.3) bigdecimal (>= 3.0) openssl (3.2.0) + opentelemetry-api (1.2.5) + opentelemetry-common (0.20.1) + opentelemetry-api (~> 1.0) + opentelemetry-exporter-otlp (0.26.3) + google-protobuf (~> 3.14) + googleapis-common-protos-types (~> 1.3) + opentelemetry-api (~> 1.1) + opentelemetry-common (~> 0.20) + opentelemetry-sdk (~> 1.2) + opentelemetry-semantic_conventions + opentelemetry-helpers-mysql (0.1.0) + opentelemetry-api (~> 1.0) + opentelemetry-common (~> 0.20) + opentelemetry-helpers-sql-obfuscation (0.1.0) + opentelemetry-common (~> 0.20) + opentelemetry-instrumentation-base (0.22.3) + opentelemetry-api (~> 1.0) + opentelemetry-registry (~> 0.1) + opentelemetry-instrumentation-delayed_job (0.22.1) + opentelemetry-api (~> 1.0) + opentelemetry-instrumentation-base (~> 0.22.1) + opentelemetry-instrumentation-http_client (0.22.3) + opentelemetry-api (~> 1.0) + opentelemetry-common (~> 0.20.0) + opentelemetry-instrumentation-base (~> 0.22.1) + opentelemetry-instrumentation-mysql2 (0.27.0) + opentelemetry-api (~> 1.0) + opentelemetry-helpers-mysql + opentelemetry-helpers-sql-obfuscation + opentelemetry-instrumentation-base (~> 0.22.1) + opentelemetry-instrumentation-net_http (0.22.4) + opentelemetry-api (~> 1.0) + opentelemetry-common (~> 0.20.0) + opentelemetry-instrumentation-base (~> 0.22.1) + opentelemetry-instrumentation-pg (0.27.1) + opentelemetry-api (~> 1.0) + opentelemetry-helpers-sql-obfuscation + opentelemetry-instrumentation-base (~> 0.22.1) + opentelemetry-instrumentation-rake (0.2.1) + opentelemetry-api (~> 1.0) + opentelemetry-instrumentation-base (~> 0.22.1) + opentelemetry-instrumentation-redis (0.25.3) + opentelemetry-api (~> 1.0) + opentelemetry-common (~> 0.20.0) + opentelemetry-instrumentation-base (~> 0.22.1) + opentelemetry-propagator-b3 (0.21.0) + opentelemetry-api (~> 1.1) + opentelemetry-propagator-jaeger (0.21.1) + opentelemetry-api (~> 1.1) + opentelemetry-propagator-xray (0.22.1) + opentelemetry-api (~> 1.0) + opentelemetry-registry (0.3.0) + opentelemetry-api (~> 1.1) + opentelemetry-sdk (1.4.0) + opentelemetry-api (~> 1.1) + opentelemetry-common (~> 0.20) + opentelemetry-registry (~> 0.2) + opentelemetry-semantic_conventions + opentelemetry-semantic_conventions (1.10.0) + opentelemetry-api (~> 1.0) os (1.1.4) palm_civet (1.1.0) parallel (1.24.0) @@ -635,6 +695,18 @@ DEPENDENCIES nokogiri (>= 1.10.5) oj openssl (>= 3.2) + opentelemetry-exporter-otlp (~> 0.26.1) + opentelemetry-instrumentation-delayed_job (~> 0.22.1) + opentelemetry-instrumentation-http_client (~> 0.22.3) + opentelemetry-instrumentation-mysql2 (~> 0.27.0) + opentelemetry-instrumentation-net_http (~> 0.22.4) + opentelemetry-instrumentation-pg (~> 0.27.1) + opentelemetry-instrumentation-rake (~> 0.2.1) + opentelemetry-instrumentation-redis (~> 0.25.3) + opentelemetry-propagator-b3 + opentelemetry-propagator-jaeger (~> 0.21.0) + opentelemetry-propagator-xray (~> 0.22.1) + opentelemetry-sdk (~> 1.3) palm_civet parallel_tests pg diff --git a/app/jobs/cc_job.rb b/app/jobs/cc_job.rb index cade751539f..e2dad588d11 100644 --- a/app/jobs/cc_job.rb +++ b/app/jobs/cc_job.rb @@ -1,6 +1,8 @@ module VCAP::CloudController module Jobs class CCJob + attr_accessor :otel_tracing_carrier + def reschedule_at(time, attempts) time + (attempts**4) + 5 end diff --git a/app/jobs/enqueuer.rb b/app/jobs/enqueuer.rb index 1d3ac32aca7..b9002ad19ff 100644 --- a/app/jobs/enqueuer.rb +++ b/app/jobs/enqueuer.rb @@ -5,6 +5,7 @@ require 'jobs/logging_context_job' require 'jobs/timeout_job' require 'securerandom' +require 'opentelemetry/sdk' module VCAP::CloudController module Jobs @@ -26,8 +27,12 @@ def enqueue_pollable(existing_guid: nil) wrapped_job = yield wrapped_job if block_given? - delayed_job = enqueue_job(wrapped_job) - PollableJobModel.find_by_delayed_job(delayed_job) + tracer = OpenTelemetry.tracer_provider.tracer(self.class.name, '1.0.0') + job_handler = wrapped_job.handler.class.name.respond_to?(:split) ? wrapped_job.handler.class.name.split('::').last : wrapped_job.handler.class.name + tracer.in_span("enqueue-job: #{job_handler}", kind: :producer) do + delayed_job = enqueue_job(wrapped_job) + PollableJobModel.find_by_delayed_job(delayed_job) + end end def run_inline @@ -42,7 +47,10 @@ def enqueue_job(job) @opts['guid'] = SecureRandom.uuid request_id = ::VCAP::Request.current_id timeout_job = TimeoutJob.new(job, job_timeout) - logging_context_job = LoggingContextJob.new(timeout_job, request_id) + logging_context_job = LoggingContextJob.new( + timeout_job, + request_id + ) @opts[:priority] = job_priority unless @opts[:priority] || job_priority.nil? Delayed::Job.enqueue(logging_context_job, @opts) end diff --git a/app/jobs/logging_context_job.rb b/app/jobs/logging_context_job.rb index 41e837c5713..cdbf404127c 100644 --- a/app/jobs/logging_context_job.rb +++ b/app/jobs/logging_context_job.rb @@ -1,5 +1,6 @@ require 'jobs/wrapping_job' require 'presenters/error_presenter' +require 'opentelemetry/sdk' module VCAP::CloudController module Jobs diff --git a/app/jobs/wrapping_job.rb b/app/jobs/wrapping_job.rb index 827df00e906..06e92afc715 100644 --- a/app/jobs/wrapping_job.rb +++ b/app/jobs/wrapping_job.rb @@ -1,9 +1,11 @@ require 'jobs/cc_job' +require 'opentelemetry-sdk' module VCAP::CloudController module Jobs class WrappingJob < VCAP::CloudController::Jobs::CCJob attr_reader :handler + attr_accessor :otel_api_trace_carrier, :otel_job_trace_carrier def initialize(handler) @handler = handler diff --git a/config/cloud_controller.yml b/config/cloud_controller.yml index 748a705f6e7..cad154a226e 100644 --- a/config/cloud_controller.yml +++ b/config/cloud_controller.yml @@ -402,3 +402,16 @@ custom_metric_tag_prefix_list: ["metric.tag.cloudfoundry.org"] max_manifest_service_binding_poll_duration_in_seconds: 60 update_metric_tags_on_rename: true + +otel: + tracing: + enabled: false + api_url: '' + api_token: '' + sampling_ratio: 1.0 + redact: + db_statements: true + propagation: + accept_sampling_instruction: true + extractors: ['tracecontext', 'xray', 'jaeger', 'baggage', 'b3', 'b3multi'] + injectors: ['tracecontext', 'xray', 'jaeger', 'baggage', 'b3', 'b3multi'] \ No newline at end of file diff --git a/config/initializers/cloudfront_signer.rb b/config/initializers/cloudfront_signer.rb index 87a06d4def3..e46b521587a 100644 --- a/config/initializers/cloudfront_signer.rb +++ b/config/initializers/cloudfront_signer.rb @@ -1,7 +1,7 @@ require 'cloudfront-signer' module CCInitializers - def self.cloudfront_signer(cc_config) + def self.cloudfront_signer(cc_config, _) return if cc_config[:droplets].blank? cdn_config = cc_config[:droplets][:cdn] diff --git a/config/initializers/delayed_job.rb b/config/initializers/delayed_job.rb index 15fb0ce0fc0..280a09e8616 100644 --- a/config/initializers/delayed_job.rb +++ b/config/initializers/delayed_job.rb @@ -1,5 +1,5 @@ module CCInitializers - def self.delayed_job(_) + def self.delayed_job(_, _) ::Delayed::Worker.backend = :sequel end end diff --git a/config/initializers/honeycomb.rb b/config/initializers/honeycomb.rb index 73f3be87656..b1fb6a75fd7 100644 --- a/config/initializers/honeycomb.rb +++ b/config/initializers/honeycomb.rb @@ -1,7 +1,7 @@ require 'honeycomb-beeline' module CCInitializers - def self.honeycomb(cc_config) + def self.honeycomb(cc_config, _) return unless cc_config[:honeycomb] Honeycomb.configure do |hc| diff --git a/config/initializers/inflections.rb b/config/initializers/inflections.rb index d623708d7c1..54d19a07d9c 100644 --- a/config/initializers/inflections.rb +++ b/config/initializers/inflections.rb @@ -1,5 +1,5 @@ module CCInitializers - def self.inflections(_) + def self.inflections(_, _) ActiveSupport::Inflector.inflections(:en) do |inflect| inflect.irregular 'quota', 'quotas' end diff --git a/config/initializers/json.rb b/config/initializers/json.rb index bb2d1402ccb..6d5a2e42cb0 100644 --- a/config/initializers/json.rb +++ b/config/initializers/json.rb @@ -1,7 +1,7 @@ require 'active_support/json/encoding' module CCInitializers - def self.json(_cc_config) + def self.json(_, _) MultiJson.use(:oj) Oj::Rails.optimize # Use optimized encoders instead of as_json() methods for available classes. Oj.default_options = { diff --git a/config/initializers/opentelemetry.rb b/config/initializers/opentelemetry.rb new file mode 100644 index 00000000000..5ee726da050 --- /dev/null +++ b/config/initializers/opentelemetry.rb @@ -0,0 +1,94 @@ +require 'opentelemetry/sdk' +require 'opentelemetry/exporter/otlp' +require 'opentelemetry/instrumentation/http_client' +require 'opentelemetry/instrumentation/net/http' +require 'opentelemetry/instrumentation/mysql2' +require 'opentelemetry/instrumentation/redis' +require 'opentelemetry/instrumentation/rake' +require 'opentelemetry/instrumentation/pg' +require 'opentelemetry/propagator/jaeger' +require 'opentelemetry/propagator/xray' +require 'delayed_job/opentelemetry/instrumentation' + +module CCInitializers + def self.opentelemetry(cc_config, context) + return unless cc_config.dig(:otel, :tracing, :enabled) + + OpenTelemetry.logger = Steno.logger(context == :api ? 'cc.api.opentelemetry' : 'cc.background.opentelemetry') + + trace_api_url = cc_config[:otel][:tracing][:api_url] + trace_api_token = cc_config[:otel][:tracing][:api_token] + sampler = OpenTelemetry::SDK::Trace::Samplers.trace_id_ratio_based(cc_config[:otel][:tracing][:sampling_ratio]) + sampler = OpenTelemetry::SDK::Trace::Samplers.parent_based(root: sampler) if cc_config.dig(:otel, :tracing, :propagation, :accept_sampling_instruction) + + OpenTelemetry::SDK.configure do |c| + c.add_span_processor( + OpenTelemetry::SDK::Trace::Export::BatchSpanProcessor.new( + OpenTelemetry::Exporter::OTLP::Exporter.new( + endpoint: trace_api_url, + headers: { + Authorization: trace_api_token + } + ) + ) + ) + version = { + V3: VCAP::CloudController::Constants::API_VERSION_V3.to_s, + V2: VCAP::CloudController::Constants::API_VERSION.to_s, + OSBAPI: VCAP::CloudController::Constants::OSBAPI_VERSION.to_s + } + # Set the service name to cloud_controller_ng_api if it is the webserver process and to cloud_controller_ng_worker if it is the worker process + resource = OpenTelemetry::SDK::Resources::Resource + conventions = OpenTelemetry::SemanticConventions::Resource + c.resource = resource.create({ + conventions::SERVICE_NAMESPACE => 'cloud_controller_ng', + conventions::SERVICE_NAME => "cloud_controller_ng-#{context}", + conventions::SERVICE_VERSION => version.to_json, + conventions::SERVICE_INSTANCE_ID => Socket.gethostname + ':' + Process.pid.to_s, + conventions::HOST_NAME => Socket.gethostname + }) + + c.use 'OpenTelemetry::Instrumentation::HttpClient' + c.use 'OpenTelemetry::Instrumentation::Net::HTTP' + c.use 'OpenTelemetry::Instrumentation::Redis' + c.use 'OpenTelemetry::Instrumentation::Rake' + c.use 'OpenTelemetry::Instrumentation::CCDelayedJob' + unless defined?(::PG).nil? + c.use 'OpenTelemetry::Instrumentation::PG', { + db_statement: (cc_config[:otel][:tracing][:redact][:db_statement] ? :obfuscate : :include) + } + end + unless defined?(::Mysql2).nil? + c.use 'OpenTelemetry::Instrumentation::Mysql2', { + db_statement: (cc_config[:otel][:tracing][:redact][:db_statement] ? :obfuscate : :include) + } + end + end + + # Configuration of sampling + OpenTelemetry.tracer_provider.sampler = sampler if trace_api_url && !trace_api_url.empty? && !trace_api_token.empty? + + extractors = define_propagators(cc_config.dig(:otel, :tracing, :propagation, :extractors)) + injectors = define_propagators(cc_config.dig(:otel, :tracing, :propagation, :injectors)) + + OpenTelemetry.propagation = OpenTelemetry::Context::Propagation::CompositeTextMapPropagator.compose(injectors:, extractors:) + end + + def self.define_propagators(config_propagators) + config_propagators = ['none'] if config_propagators.nil? + config_propagators.uniq.collect do |propagator| + case propagator + when 'tracecontext' then OpenTelemetry::Trace::Propagation::TraceContext.text_map_propagator + when 'baggage' then OpenTelemetry::Baggage::Propagation.text_map_propagator + when 'b3' then OpenTelemetry::Propagator::B3::Single.text_map_propagator + when 'b3multi' then OpenTelemetry::Propagator::B3::Multi.text_map_propagator + when 'jaeger' then OpenTelemetry::Propagator::Jaeger.text_map_propagator + when 'xray' then OpenTelemetry::Propagator::XRay.text_map_propagator + when 'none' then OpenTelemetry::SDK::Configurator::NoopTextMapPropagator.new + else + OpenTelemetry.logger.warn "The #{propagator} propagator is unknown and cannot be configured" + OpenTelemetry::SDK::Configurator::NoopTextMapPropagator.new + end + end + end +end diff --git a/config/initializers/wrap_parameters.rb b/config/initializers/wrap_parameters.rb index 70c6086cd59..d91747a9bac 100644 --- a/config/initializers/wrap_parameters.rb +++ b/config/initializers/wrap_parameters.rb @@ -3,7 +3,7 @@ # This file contains settings for ActionController::ParamsWrapper which # is enabled by default. module CCInitializers - def self.wrap_parameters(_) + def self.wrap_parameters(_, _) # Enable parameter wrapping for JSON. You can disable this by setting :format to an empty array. ActiveSupport.on_load(:action_controller) do wrap_parameters format: [] diff --git a/config/newrelic/initializers/new_relic_app_observer_instrumentation.rb b/config/newrelic/initializers/new_relic_app_observer_instrumentation.rb index 2c2539fb478..a30ec98cc2b 100644 --- a/config/newrelic/initializers/new_relic_app_observer_instrumentation.rb +++ b/config/newrelic/initializers/new_relic_app_observer_instrumentation.rb @@ -2,7 +2,7 @@ require 'cloud_controller/process_observer' module CCInitializers - def self.new_relic_app_observer_instrumentation(_) + def self.new_relic_app_observer_instrumentation(_, _) VCAP::CloudController::ProcessObserver.class_eval do include ::NewRelic::Agent::MethodTracer diff --git a/config/newrelic/initializers/new_relic_enable_gc_profiler.rb b/config/newrelic/initializers/new_relic_enable_gc_profiler.rb index e9d51acb2c6..585382acab2 100644 --- a/config/newrelic/initializers/new_relic_enable_gc_profiler.rb +++ b/config/newrelic/initializers/new_relic_enable_gc_profiler.rb @@ -1,7 +1,7 @@ require 'newrelic_rpm' module CCInitializers - def self.new_relic_enable_gc_profiler(_) + def self.new_relic_enable_gc_profiler(_, _) # NewRelic agent's CoreGCProfiler will clear GC stats GC::Profiler.enable end diff --git a/config/newrelic/initializers/new_relic_loggregator_instrumentation.rb b/config/newrelic/initializers/new_relic_loggregator_instrumentation.rb index 6ba28668183..314608bc093 100644 --- a/config/newrelic/initializers/new_relic_loggregator_instrumentation.rb +++ b/config/newrelic/initializers/new_relic_loggregator_instrumentation.rb @@ -2,7 +2,7 @@ require 'app_log_emitter' module CCInitializers - def self.new_relic_loggregator_instrumentation(_) + def self.new_relic_loggregator_instrumentation(_, _) VCAP::AppLogEmitter.class_eval do include ::NewRelic::Agent::MethodTracer diff --git a/lib/cloud_controller.rb b/lib/cloud_controller.rb index 6bf61f25d8d..f444c0f9d60 100644 --- a/lib/cloud_controller.rb +++ b/lib/cloud_controller.rb @@ -34,9 +34,10 @@ module VCAP::CloudController; end require 'cloud_controller/errors/buildpack_error' require 'cloud_controller/errors/v3/api_error' require 'cloud_controller/errors/v3/details' -require 'delayed_job_plugins/deserialization_retry' -require 'delayed_job_plugins/before_enqueue_hook' -require 'delayed_job_plugins/after_enqueue_hook' +require 'delayed_job/plugins/deserialization_retry' +require 'delayed_job/plugins/before_enqueue_hook' +require 'delayed_job/plugins/after_enqueue_hook' + require 'sequel_plugins/sequel_plugins' require 'vcap/sequel_add_association_dependencies_monkeypatch' require 'access/access' diff --git a/lib/cloud_controller/config.rb b/lib/cloud_controller/config.rb index ae6aa808c69..a7e85056a81 100644 --- a/lib/cloud_controller/config.rb +++ b/lib/cloud_controller/config.rb @@ -99,10 +99,11 @@ def valid_in_userinfo?(value) end end - attr_reader :config_hash + attr_reader :config_hash, :context def initialize(config_hash, context: :api) @config_hash = config_hash + @context = context @schema_class = self.class.schema_class_for_context(context, config_hash) end @@ -181,7 +182,7 @@ def run_initializers_in_directory(path) Dir.glob(File.expand_path(path, __FILE__)).each do |file| require file method = File.basename(file).sub('.rb', '').tr('-', '_') - CCInitializers.send(method, @config_hash) + CCInitializers.send(method, @config_hash, @context) end end end diff --git a/lib/cloud_controller/config_schemas/base/api_schema.rb b/lib/cloud_controller/config_schemas/base/api_schema.rb index 953775d83b4..7314089d4fd 100644 --- a/lib/cloud_controller/config_schemas/base/api_schema.rb +++ b/lib/cloud_controller/config_schemas/base/api_schema.rb @@ -375,7 +375,24 @@ class ApiSchema < VCAP::Config dataset: String }, - update_metric_tags_on_rename: bool + update_metric_tags_on_rename: bool, + + otel: { + tracing: { + enabled: bool, + api_url: String, + api_token: String, + sampling_ratio: Float, + redact: { + db_statements: bool + }, + propagation: { + accept_sampling_instruction: bool, + extractors: Array, + injectors: Array + } + } + } } end # rubocop:enable Metrics/BlockLength diff --git a/lib/cloud_controller/config_schemas/base/worker_schema.rb b/lib/cloud_controller/config_schemas/base/worker_schema.rb index 224448bbfde..46b498bb0fc 100644 --- a/lib/cloud_controller/config_schemas/base/worker_schema.rb +++ b/lib/cloud_controller/config_schemas/base/worker_schema.rb @@ -182,7 +182,24 @@ class WorkerSchema < VCAP::Config max_labels_per_resource: Integer, max_annotations_per_resource: Integer, internal_route_vip_range: String, - custom_metric_tag_prefix_list: Array + custom_metric_tag_prefix_list: Array, + + otel: { + tracing: { + enabled: bool, + api_url: String, + api_token: String, + sampling_ratio: Float, + redact: { + db_statements: bool + }, + propagation: { + accept_sampling_instruction: bool, + extractors: Array, + injectors: Array + } + } + } } end # rubocop:enable Metrics/BlockLength diff --git a/lib/cloud_controller/rack_app_builder.rb b/lib/cloud_controller/rack_app_builder.rb index 7de1c836d4b..7e600bf6791 100644 --- a/lib/cloud_controller/rack_app_builder.rb +++ b/lib/cloud_controller/rack_app_builder.rb @@ -9,12 +9,14 @@ require 'service_broker_rate_limiter' require 'rate_limiter_v2_api' require 'new_relic_custom_attributes' -require 'zipkin' require 'block_v3_only_roles' +require 'open_telemetry_middleware' +require 'opentelemetry/sdk' require 'below_min_cli_warning' module VCAP::CloudController class RackAppBuilder + # rubocop:disable Metrics/BlockLength, Metrics/CyclomaticComplexity def build(config, request_metrics, request_logs) token_decoder = VCAP::CloudController::UaaTokenDecoder.new(config.get(:uaa)) configurer = VCAP::CloudController::Security::SecurityContextConfigurer.new(token_decoder) @@ -22,6 +24,7 @@ def build(config, request_metrics, request_logs) logger = access_log(config) Rack::Builder.new do + use CloudFoundry::Middleware::OpenTelemetryFirstMiddleware if config.get(:otel, :tracing, :enabled) use CloudFoundry::Middleware::RequestMetrics, request_metrics use CloudFoundry::Middleware::Cors, config.get(:allowed_cors_domains) use CloudFoundry::Middleware::VcapRequestId @@ -29,7 +32,6 @@ def build(config, request_metrics, request_logs) use CloudFoundry::Middleware::NewRelicCustomAttributes if config.get(:newrelic_enabled) use Honeycomb::Rack::Middleware, client: Honeycomb.client if config.get(:honeycomb) use CloudFoundry::Middleware::SecurityContextSetter, configurer - use CloudFoundry::Middleware::Zipkin use CloudFoundry::Middleware::RequestLogs, request_logs if config.get(:rate_limiter, :enabled) use CloudFoundry::Middleware::RateLimiter, { @@ -64,18 +66,22 @@ def build(config, request_metrics, request_logs) map '/' do use CloudFoundry::Middleware::BlockV3OnlyRoles, { logger: Steno.logger('cc.unsupported_roles') } + use CloudFoundry::Middleware::OpenTelemetryLastMiddleware if config.get(:otel, :tracing, :enabled) run FrontController.new(config) end map '/v3' do + use CloudFoundry::Middleware::OpenTelemetryLastMiddleware if config.get(:otel, :tracing, :enabled) run Rails.application.app end map '/healthz' do + use CloudFoundry::Middleware::OpenTelemetryLastMiddleware if config.get(:otel, :tracing, :enabled) run ->(_) { [200, { 'Content-Type' => 'application/json' }, ['OK']] } end end end + # rubocop:enable Metrics/BlockLength, Metrics/CyclomaticComplexity private diff --git a/lib/delayed_job/opentelemetry/instrumentation.rb b/lib/delayed_job/opentelemetry/instrumentation.rb new file mode 100644 index 00000000000..38c09fce6ed --- /dev/null +++ b/lib/delayed_job/opentelemetry/instrumentation.rb @@ -0,0 +1,11 @@ +# frozen_string_literal: true + +# Copyright The OpenTelemetry Authors +# +# SPDX-License-Identifier: Apache-2.0 +module OpenTelemetry + module Instrumentation + end +end + +require_relative 'instrumentation/cc_delayed_job' diff --git a/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job.rb b/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job.rb new file mode 100644 index 00000000000..157294fa5ae --- /dev/null +++ b/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job.rb @@ -0,0 +1,18 @@ +# frozen_string_literal: true + +# Copyright The OpenTelemetry Authors +# +# SPDX-License-Identifier: Apache-2.0 + +require 'opentelemetry' +require 'opentelemetry-instrumentation-base' + +module OpenTelemetry + module Instrumentation + module CCDelayedJob + end + end +end + +require_relative 'cc_delayed_job/instrumentation' +require_relative 'cc_delayed_job/version' diff --git a/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job/instrumentation.rb b/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job/instrumentation.rb new file mode 100644 index 00000000000..98336c4d556 --- /dev/null +++ b/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job/instrumentation.rb @@ -0,0 +1,42 @@ +# frozen_string_literal: true + +# Copyright The OpenTelemetry Authors +# +# SPDX-License-Identifier: Apache-2.0 + +module OpenTelemetry + module Instrumentation + module CCDelayedJob + # Instrumentation class that detects and installs the DelayedJob instrumentation + class Instrumentation < OpenTelemetry::Instrumentation::Base + MINIMUM_VERSION = Gem::Version.new('4.1') + + install do |_config| + require_dependencies + register_tracer_plugin + end + + present do + !defined?(::Delayed).nil? + end + + compatible do + # Version is hardcoded in the gemspec + # https://github.com/collectiveidea/delayed_job/blob/master/delayed_job.gemspec#L16 + gem_version = Gem.loaded_specs['delayed_job']&.version + gem_version && gem_version >= MINIMUM_VERSION + end + + private + + def require_dependencies + require_relative 'plugins/tracer_plugin' + end + + def register_tracer_plugin + ::Delayed::Worker.plugins << Plugins::TracerPlugin + end + end + end + end +end diff --git a/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job/plugins/tracer_plugin.rb b/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job/plugins/tracer_plugin.rb new file mode 100644 index 00000000000..a9667465c67 --- /dev/null +++ b/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job/plugins/tracer_plugin.rb @@ -0,0 +1,223 @@ +# frozen_string_literal: true + +# Copyright The OpenTelemetry Authors +# +# SPDX-License-Identifier: Apache-2.0 + +require 'delayed/plugin' + +module OpenTelemetry + module Instrumentation + module CCDelayedJob + module Plugins + # Delayed Job plugin that instruments invoke_job and other hooks + class TracerPlugin < Delayed::Plugin + class << self + def instrument_enqueue(job) + return yield(job) unless enabled? + + job_payload = job.payload_object + + attributes = build_attributes(job) + attributes['messaging.operation'] = 'publish' + attributes.compact! + + # Inject a new context into the job payload for linking this span to the job span + links = [] + if job_payload.respond_to?(:otel_job_trace_carrier=) + job_span = Trace::Span.new(span_context: Trace::SpanContext.new(trace_flags: current_span_context.trace_flags)) + Context.with_current(Trace.context_with_span(job_span)) do + job_payload.otel_job_trace_carrier = {}.tap { |carrier| propagator.inject(carrier) } + end + links = [Trace::Link.new(job_span.context, attributes:)] + end + + tracer.in_span("DelayedJobQueue #{job_queue(job)}: #{job_name(job)} enqueue", attributes: attributes, kind: :producer, links: links) do |span| + # Inject the current context into the job payload for linking the job to this span + job_payload.otel_api_trace_carrier = {}.tap { |carrier| propagator.inject(carrier) } if job_payload.respond_to?(:otel_api_trace_carrier=) + + # Persist changes in the job payload + job.payload_object = job_payload + + yield job + span.set_attribute('messaging.message_id', job.id.to_s) + add_events(span, job) + end + end + + def instrument_invoke(job) + return yield(job) unless enabled? + + # Add attributes to the span + attributes = build_attributes(job) + attributes['messaging.delayed_job.attempts'] = job.attempts if job.attempts + attributes['messaging.delayed_job.locked_by'] = job.locked_by if job.locked_by + attributes['messaging.operation'] = 'process' + attributes['messaging.message_id'] = job.id.to_s + attributes.compact! + + # Extract the apis context from the job payload to link this job to the api span + api_context = Context.new({}) + api_context = propagator.extract(job.payload_object.otel_api_trace_carrier) if job.payload_object.respond_to?(:otel_api_trace_carrier) + + # Extract the jobs context from the job payload to use it since it was already linked by the span of the api + job_context = Context.new({}) + job_context = propagator.extract(job.payload_object.otel_job_trace_carrier) if job.payload_object.respond_to?(:otel_job_trace_carrier) + + # Set a link to the api span if it exists + api_span_context = current_span_context(context: api_context) + links = api_span_context.valid? ? [Trace::Link.new(api_span_context, attributes:)] : [] + + # Reuse the producer has propagator to the consumer, in case of a invalid job span or a retried job we create a new context + Context.with_current(job_context) do + job_root_span = start_predefined_root_span(job, links: links, attributes: attributes, kind: :consumer) + Trace.with_span(job_root_span) do |span| + # Set the logger to include the propagated trace context values for compatibility with the zipkin middleware + if OpenTelemetry::Trace.current_span.context.valid? + Steno.config.context.data['otel_trace_id'] = OpenTelemetry::Trace.current_span.context.trace_id.unpack1('H*') + Steno.config.context.data['otel_span_id'] = OpenTelemetry::Trace.current_span.context.span_id.unpack1('H*') + else + Steno.config.context.data.delete('otel_trace_id') + Steno.config.context.data.delete('otel_span_id') + end + # Add events to the span + add_events(span, job) + # Call the job + yield job + end + rescue Exception => e # rubocop:disable Lint/RescueException + job_root_span&.record_exception(e) + job_root_span&.status = Status.error("Unhandled exception of type: #{e.class}") + raise e + ensure + job_root_span&.finish + end + end + + private + + def start_predefined_root_span(job, kind: :consumer, attributes: {}, links: []) + span = Trace.current_span + span_context = span.context + span_name = "DelayedJobQueue #{job_queue(job)}: #{job_name(job)} process" + attempts = job.respond_to?(:attempts) ? job.attempts : 0 + if span_context.valid? && attempts == 0 + start_current_span(span, span_name, kind, attributes, links) + else + tracer.start_span(span_name, attributes:, links:, kind:) + end + end + + def start_current_span(span, name, kind, attributes, links) + span_id = span.context.span_id + trace_id = span.context.trace_id + + sampler = SDK::Trace::Samplers.parent_based(root: SDK::Trace::Samplers::ALWAYS_OFF) + result = sampler.should_sample?(trace_id: trace_id, parent_context: nil, links: links, name: name, kind: kind, attributes: attributes) + + return Trace.non_recording_span(Trace::SpanContext.new(trace_id: trace_id, span_id: span_id, tracestate: result.tracestate)) unless result.recording? && !@stopped + + trace_flags = result.sampled? ? Trace::TraceFlags::SAMPLED : Trace::TraceFlags::DEFAULT + context = 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 + + create_new_span(context, name, kind, attributes, links) + end + + def create_new_span(context, name, kind, attributes, links) + SDK::Trace::Span.new( + context, + Context.empty, + Trace::Span::INVALID, + name, + kind, + Trace::SpanContext::INVALID.span_id, + tracer_provider_span_limits, + tracer_provider_span_processors, + attributes, + links, + nil, + tracer_provider_resource, + tracer_instrumentation_scope + ) + end + + def current_span_context(context: Context.current) + Context.with_current(context) { Trace.current_span.context } + end + + def build_attributes(job) + { + 'messaging.system' => 'delayed_job', + 'messaging.destination' => job_queue(job), + 'messaging.destination_kind' => 'queue', + 'messaging.delayed_job.name' => job_name(job), + 'messaging.delayed_job.guid' => job_guid(job), + 'messaging.delayed_job.priority' => job.priority + } + end + + def add_events(span, job) + span.add_event('run_at', timestamp: job.run_at) if job.run_at + span.add_event('locked_at', timestamp: job.locked_at) if job.locked_at + end + + def enabled? + CCDelayedJob::Instrumentation.instance.enabled? + end + + def tracer + CCDelayedJob::Instrumentation.instance.tracer + end + + def tracer_provider_span_limits + tracer.instance_variable_get(:@tracer_provider).instance_variable_get(:@span_limits) + end + + def tracer_provider_span_processors + tracer.instance_variable_get(:@tracer_provider).instance_variable_get(:@span_processors) + end + + def tracer_provider_resource + tracer.instance_variable_get(:@tracer_provider).instance_variable_get(:@resource) + end + + def tracer_instrumentation_scope + tracer.instance_variable_get(:@instrumentation_scope) + end + + def propagator + @propagator ||= Trace::Propagation::TraceContext::TextMapPropagator.new + end + + def job_name(job) + # If Delayed Job is used via ActiveJob then get the job name from the payload + if job.payload_object.respond_to?(:job_data) + job.payload_object.job_data['job_class'] + else + job.name + end + end + + def job_queue(job) + job.queue || 'default' + end + + def job_guid(job) + if job.respond_to?(:guid) + job.guid + else + '' + end + end + end + + callbacks do |lifecycle| + lifecycle.around(:enqueue, &method(:instrument_enqueue)) + lifecycle.around(:invoke_job, &method(:instrument_invoke)) + end + end + end + end + end +end diff --git a/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job/version.rb b/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job/version.rb new file mode 100644 index 00000000000..04948e2f21b --- /dev/null +++ b/lib/delayed_job/opentelemetry/instrumentation/cc_delayed_job/version.rb @@ -0,0 +1,13 @@ +# frozen_string_literal: true + +# Copyright The OpenTelemetry Authors +# +# SPDX-License-Identifier: Apache-2.0 + +module OpenTelemetry + module Instrumentation + module CCDelayedJob + VERSION = '0.22.1' + end + end +end diff --git a/lib/delayed_job_plugins/after_enqueue_hook.rb b/lib/delayed_job/plugins/after_enqueue_hook.rb similarity index 100% rename from lib/delayed_job_plugins/after_enqueue_hook.rb rename to lib/delayed_job/plugins/after_enqueue_hook.rb diff --git a/lib/delayed_job_plugins/before_enqueue_hook.rb b/lib/delayed_job/plugins/before_enqueue_hook.rb similarity index 100% rename from lib/delayed_job_plugins/before_enqueue_hook.rb rename to lib/delayed_job/plugins/before_enqueue_hook.rb diff --git a/lib/delayed_job_plugins/deserialization_retry.rb b/lib/delayed_job/plugins/deserialization_retry.rb similarity index 100% rename from lib/delayed_job_plugins/deserialization_retry.rb rename to lib/delayed_job/plugins/deserialization_retry.rb diff --git a/lib/services/service_brokers/v2/http_client.rb b/lib/services/service_brokers/v2/http_client.rb index 0683abb5730..28837154a17 100644 --- a/lib/services/service_brokers/v2/http_client.rb +++ b/lib/services/service_brokers/v2/http_client.rb @@ -1,4 +1,6 @@ require 'httpclient' +require 'opentelemetry/sdk' +require 'opentelemetry-propagator-b3' module VCAP::Services module ServiceBrokers::V2 @@ -66,9 +68,6 @@ def make_request(method, uri, body=nil, options={}) user_guid = user_guid(options) opts[:header][VCAP::Request::HEADER_BROKER_API_ORIGINATING_IDENTITY] = IdentityEncoder.encode(user_guid) if user_guid - opts[:header][VCAP::Request::HEADER_ZIPKIN_B3_TRACEID] = VCAP::Request.b3_trace_id if VCAP::Request.b3_trace_id - opts[:header][VCAP::Request::HEADER_ZIPKIN_B3_SPANID] = VCAP::Request.b3_span_id if VCAP::Request.b3_span_id - headers = client.default_header.merge(opts[:header]) logger.info 'request', method: method, url: uri.to_s diff --git a/lib/vcap/request.rb b/lib/vcap/request.rb index 0b70a05730c..f446ed8f7e9 100644 --- a/lib/vcap/request.rb +++ b/lib/vcap/request.rb @@ -5,8 +5,6 @@ module Request HEADER_API_INFO_LOCATION = 'X-Api-Info-Location'.freeze HEADER_BROKER_API_ORIGINATING_IDENTITY = 'X-Broker-Api-Originating-Identity'.freeze HEADER_BROKER_API_REQUEST_IDENTITY = 'X-Broker-API-Request-Identity'.freeze - HEADER_ZIPKIN_B3_TRACEID = 'X-B3-TraceId'.freeze - HEADER_ZIPKIN_B3_SPANID = 'X-B3-SpanId'.freeze class << self def current_id=(request_id) @@ -29,32 +27,6 @@ def user_guid=(user_guid) Steno.config.context.data['user_guid'] = user_guid end end - - def b3_trace_id=(trace_id) - Thread.current[:b3_trace_id] = trace_id - if trace_id.nil? - Steno.config.context.data.delete('b3_trace_id') - else - Steno.config.context.data['b3_trace_id'] = trace_id - end - end - - def b3_trace_id - Thread.current[:b3_trace_id] - end - - def b3_span_id=(span_id) - Thread.current[:b3_span_id] = span_id - if span_id.nil? - Steno.config.context.data.delete('b3_span_id') - else - Steno.config.context.data['b3_span_id'] = span_id - end - end - - def b3_span_id - Thread.current[:b3_span_id] - end end end end diff --git a/middleware/open_telemetry_middleware.rb b/middleware/open_telemetry_middleware.rb new file mode 100644 index 00000000000..fb23aa28830 --- /dev/null +++ b/middleware/open_telemetry_middleware.rb @@ -0,0 +1,114 @@ +require 'opentelemetry/sdk' + +module CloudFoundry + module Middleware + class OpenTelemetryFirstMiddleware + attr_reader :initial_span, :initial_baggage + + def initialize(app) + @app = app + @tracer = OpenTelemetry.tracer_provider.tracer(self.class.name, '1.0.0') + end + + def call(env) + # Extract context from request headers + tracing_context = OpenTelemetry.propagation.extract( + env, + getter: OpenTelemetry::Common::Propagation.rack_env_getter + ) + + # Span name SHOULD be set to route: + span_name = if env['PATH_INFO'] && env['REQUEST_METHOD'] + "#{env['REQUEST_METHOD']}: #{env['PATH_INFO']}" + else + 'unknown' + end + + # Use the extracted/adopted context + OpenTelemetry::Context.with_current(tracing_context) do + # Set the logger to include the propagated trace context values for compatibility with the zipkin middleware + if OpenTelemetry::Trace.current_span.context.valid? + Steno.config.context.data['b3_trace_id'] = OpenTelemetry::Trace.current_span.context.trace_id.unpack1('H*') + Steno.config.context.data['b3_span_id'] = OpenTelemetry::Trace.current_span.context.span_id.unpack1('H*') + else + Steno.config.context.data.delete('b3_trace_id') + Steno.config.context.data.delete('b3_span_id') + end + + # Span kind MUST be `:server` for a HTTP server span + @tracer.in_span( + span_name, + attributes: { + 'http.request.method' => check_header_value(env['REQUEST_METHOD']), + 'url.path' => check_header_value(env['PATH_INFO']), + 'url.scheme' => check_header_value(env['rack.url_scheme']), + 'url.query' => check_header_value(env['QUERY_STRING']), + 'url.full' => check_header_value(env['REQUEST_URI']), + 'http.host' => check_header_value(env['HTTP_HOST']), + 'user_agent.original' => check_header_value(env['HTTP_USER_AGENT']), + 'http.request.header.connection' => check_header_value(env['HTTP_CONNECTION']), + 'http.request.header.version' => check_header_value(env['HTTP_VERSION']), + 'http.request.header.x_real_ip' => check_header_value(env['HTTP_X_REAL_IP']), + 'http.request.header.x_forwared_for' => check_header_value(env['HTTP_X_FORWARDED_FOR']), + 'http.request.header.accept' => check_header_value(env['HTTP_ACCEPT']), + 'http.request.header.accept_encoding' => check_header_value(env['HTTP_ACCEPT_ENCODING']), + 'http.request.body.size' => check_header_value(env['CONTENT_LENGTH']) + }, + kind: :server + ) do |span| + # Propagate the current span so others can add attributes to it + env['otel_root_span'] = OpenTelemetry::Trace.current_span + + # Set the logger to include trace context values in logs + Steno.config.context.data['otel_trace_id'] = OpenTelemetry::Trace.current_span.context.trace_id.unpack1('H*') + Steno.config.context.data['otel_span_id'] = OpenTelemetry::Trace.current_span.context.span_id.unpack1('H*') + + # Trace the middleware execution time + middleware_pre_app_span = @tracer.start_span('Middlewares') + OpenTelemetry::Trace.with_span(middleware_pre_app_span) do + @status, @headers, @body = @app.call(env) + rescue Exception => e # rubocop:disable Lint/RescueException + span.record_exception(e) + span.status = OpenTelemetry::Trace::Status.error("Exception: #{e.class} - #{e.message}") + raise e + end + # Set return attributes + span.set_attribute('http.response.status_code', @status) + span.set_attribute('http.response.body.size', @body.respond_to?(:bytesize) ? @body.bytesize : 0) + end + + [@status, @headers, @body] + end + end + + def check_header_value(header_value) + return '' unless header_value.is_a? String + + return '' if header_value.empty? + + return '' if header_value.bytesize > 100_000 + + header_value + end + end + + class OpenTelemetryLastMiddleware + def initialize(app) + @app = app + @tracer = OpenTelemetry.tracer_provider.tracer(self.class.name, '1.0.0') + end + + def call(env) + # Close the span that measures middlewares without application runtime + OpenTelemetry::Trace.current_span.finish + + # Measure application runtime in a seperate span + @tracer.in_span('Application') do |_span| + @status, @headers, @body = @app.call(env) + end + + [@status, @headers, @body] + end + end + end +end diff --git a/middleware/vcap_request_id.rb b/middleware/vcap_request_id.rb index 6ebe12badd7..9b426001dbf 100644 --- a/middleware/vcap_request_id.rb +++ b/middleware/vcap_request_id.rb @@ -1,5 +1,6 @@ require 'securerandom' require 'active_support/core_ext/string/access' +require 'opentelemetry/sdk' module CloudFoundry module Middleware @@ -18,6 +19,7 @@ def call(env) ::VCAP::Request.current_id = nil end + env['otel_root_span'].set_attribute('http.request.header.x-vcap-request-id', env['cf.request_id']) if env['otel_root_span'] headers['X-VCAP-Request-ID'] = env['cf.request_id'] [status, headers, body] end diff --git a/middleware/zipkin.rb b/middleware/zipkin.rb deleted file mode 100644 index d90523f3238..00000000000 --- a/middleware/zipkin.rb +++ /dev/null @@ -1,43 +0,0 @@ -module CloudFoundry - module Middleware - class Zipkin - def initialize(app) - @app = app - end - - def call(env) - return call_app(env) unless env['HTTP_X_B3_TRACEID'] && env['HTTP_X_B3_SPANID'] - - env['b3.trace_id'], env['b3.span_id'] = external_b3_ids(env) - - ::VCAP::Request.b3_trace_id = env['b3.trace_id'] - ::VCAP::Request.b3_span_id = env['b3.span_id'] - - zipkin_headers = { - 'X-B3-TraceId' => env['HTTP_X_B3_TRACEID'], - 'X-B3-SpanId' => env['HTTP_X_B3_SPANID'] - } - - begin - status, headers, body = @app.call(env) - ensure - ::VCAP::Request.b3_trace_id = nil - ::VCAP::Request.b3_span_id = nil - end - - [status, headers.merge(zipkin_headers), body] - end - - def call_app(env) - @app.call(env) - end - - def external_b3_ids(env) - trace_id = env['HTTP_X_B3_TRACEID'] - span_id = env['HTTP_X_B3_SPANID'] - - [trace_id, span_id] - end - end - end -end diff --git a/spec/db_spec_helper.rb b/spec/db_spec_helper.rb index 693211c614c..9814d04b8cf 100644 --- a/spec/db_spec_helper.rb +++ b/spec/db_spec_helper.rb @@ -13,9 +13,9 @@ VCAP::CloudController::SpecBootstrap.init(recreate_test_tables: false) - require 'delayed_job_plugins/deserialization_retry' - require 'delayed_job_plugins/after_enqueue_hook' - require 'delayed_job_plugins/before_enqueue_hook' + require 'delayed_job/plugins/deserialization_retry' + require 'delayed_job/plugins/after_enqueue_hook' + require 'delayed_job/plugins/before_enqueue_hook' require 'support/fakes/blueprints' diff --git a/spec/unit/lib/cloud_controller/rack_app_builder_spec.rb b/spec/unit/lib/cloud_controller/rack_app_builder_spec.rb index 51b689ce25e..e3668513ddb 100644 --- a/spec/unit/lib/cloud_controller/rack_app_builder_spec.rb +++ b/spec/unit/lib/cloud_controller/rack_app_builder_spec.rb @@ -25,6 +25,25 @@ module VCAP::CloudController expect(CloudFoundry::Middleware::RequestLogs).to have_received(:new).with(anything, request_logs) end + describe 'OpenTelemetry Middlewares' do + before do + allow(CloudFoundry::Middleware::OpenTelemetryFirstMiddleware).to receive(:new) + allow(CloudFoundry::Middleware::OpenTelemetryLastMiddleware).to receive(:new) + end + + it 'uses OpenTelemetryMiddlewares when tracing is enabled' do + builder.build(TestConfig.override(otel: { tracing: { enabled: true, sampling_ratio: 1.0 } }), request_metrics, request_logs).to_app + expect(CloudFoundry::Middleware::OpenTelemetryFirstMiddleware).to have_received(:new) + expect(CloudFoundry::Middleware::OpenTelemetryLastMiddleware).to have_received(:new).exactly(3).times + end + + it 'does not use OpenTelemetryMiddlewares when tracing is disabled' do + builder.build(TestConfig.override(otel: { tracing: { enabled: false } }), request_metrics, request_logs).to_app + expect(CloudFoundry::Middleware::OpenTelemetryFirstMiddleware).not_to have_received(:new) + expect(CloudFoundry::Middleware::OpenTelemetryLastMiddleware).not_to have_received(:new) + end + end + describe 'Rack::CommonLogger' do before do allow(Rack::CommonLogger).to receive(:new) diff --git a/spec/unit/lib/vcap/request_spec.rb b/spec/unit/lib/vcap/request_spec.rb index 4fb4dd280fd..f57403a6b41 100644 --- a/spec/unit/lib/vcap/request_spec.rb +++ b/spec/unit/lib/vcap/request_spec.rb @@ -22,18 +22,6 @@ module VCAP end end - describe '::HEADER_ZIPKIN_B3_TRACEID' do - it 'constant is expected header name' do - expect(Request::HEADER_ZIPKIN_B3_TRACEID).to eq 'X-B3-TraceId' - end - end - - describe '::HEADER_ZIPKIN_B3_SPANID' do - it 'constant is expected header name' do - expect(Request::HEADER_ZIPKIN_B3_SPANID).to eq 'X-B3-SpanId' - end - end - describe '.current_id' do after do Request.current_id = nil @@ -67,46 +55,6 @@ module VCAP end end - describe '.b3_trace_id' do - after do - Request.b3_trace_id = nil - end - - let(:trace_id) { SecureRandom.hex(8) } - - it 'sets the new b3_trace_id value' do - Request.b3_trace_id = trace_id - - expect(Request.b3_trace_id).to eq trace_id - end - - it 'uses the :b3_trace_id thread local' do - Request.b3_trace_id = trace_id - - expect(Thread.current[:b3_trace_id]).to eq(trace_id) - end - end - - describe '.b3_span_id' do - after do - Request.b3_span_id = nil - end - - let(:span_id) { SecureRandom.hex(8) } - - it 'sets the new b3_span_id value' do - Request.b3_span_id = span_id - - expect(Request.b3_span_id).to eq span_id - end - - it 'uses the :b3_span_id thread local' do - Request.b3_span_id = span_id - - expect(Thread.current[:b3_span_id]).to eq(span_id) - end - end - describe '.user_guid' do after do Request.user_guid = nil diff --git a/spec/unit/middleware/open_telemetry_middleware_spec.rb b/spec/unit/middleware/open_telemetry_middleware_spec.rb new file mode 100644 index 00000000000..121afb13429 --- /dev/null +++ b/spec/unit/middleware/open_telemetry_middleware_spec.rb @@ -0,0 +1,1094 @@ +require 'spec_helper' +require 'open_telemetry_middleware' +require 'securerandom' +require 'opentelemetry/sdk' + +module CloudFoundry + module Middleware + RSpec.describe OpenTelemetryFirstMiddleware, OpenTelemetryLastMiddleware do + # Register Middlewares and App for Testing + let(:fake_app) { FakeApp.new } + let(:middlewares) { OpenTelemetryFirstMiddleware.new(OpenTelemetryLastMiddleware.new(fake_app)) } + + # Generate IDs for Testing + let(:trace_id) { SecureRandom.hex(16) } + let(:span_id) { SecureRandom.hex(8) } + let(:parent_span_id) { SecureRandom.hex(8) } + + class FakeApp + attr_reader :last_trace, :last_span_id, :last_parent_span_id, :last_trace_id, :last_baggage_values, :last_span_sampled, :parsed_span_id, :parsed_parent_span_id, + :parsed_trace_id, :parsed_baggage_values, :parsed_span_sampled + + def call(env) + # Record trace and baggage values to test extraction + @last_span_id = OpenTelemetry::Trace.current_span.context.span_id.unpack1('H*') + @last_parent_span_id = OpenTelemetry::Trace.current_span.respond_to?(:parent_span_id) ? OpenTelemetry::Trace.current_span.parent_span_id.unpack1('H*') : nil + @last_trace_id = OpenTelemetry::Trace.current_span.context.trace_id.unpack1('H*') + @last_baggage_values = OpenTelemetry::Baggage.values + @last_span_sampled = OpenTelemetry::Trace.current_span.context.trace_flags.sampled? + OpenTelemetry::Context.with_current(OpenTelemetry.propagation.extract(env, getter: OpenTelemetry::Common::Propagation.rack_env_getter)) do + @parsed_span_id = OpenTelemetry::Trace.current_span.context.span_id.unpack1('H*') + @parsed_parent_span_id = OpenTelemetry::Trace.current_span.respond_to?(:parent_span_id) ? OpenTelemetry::Trace.current_span.parent_span_id.unpack1('H*') : nil + @parsed_trace_id = OpenTelemetry::Trace.current_span.context.trace_id.unpack1('H*') + @parsed_baggage_values = OpenTelemetry::Baggage.values + @parsed_span_sampled = OpenTelemetry::Trace.current_span.context.trace_flags.sampled? + end + # Make outgoing http calls to test injection + OpenTelemetry::Context.with_current(OpenTelemetry::Baggage.set_value('test', 'bommel')) do + # Make a http call with Net::HTTP + http = Net::HTTP.new('fake.net_http.request') + request = Net::HTTP::Get.new('/', {}) + request.body = 'a request body' + http.start.request(request) + # Make a http call with Net::HTTP over alternative ways + Net::HTTP.get(URI('http://fake.net_http.request/')) + # Make a http call with HTTPClient + HTTPClient.new.request(:get, 'http://fake.http_client.request/', body: nil, header: {}) + end + [200, {}, 'a capi response body'] + end + end + + before do + WebMock::API.stub_request(:get, 'http://fake.net_http.request/') + WebMock::API.stub_request(:get, 'http://fake.http_client.request/') + end + + def configure_otel(extractors, injectors, sampling_ratio: 1.0, accept_sampling_instruction: false, redact_db_statement: true) + TestConfig.override( + otel: { + tracing: { + enabled: true, + api_url: 'http://fake.request', + api_token: '123', + sampling_ratio: sampling_ratio, + redact: { + db_statement: redact_db_statement + }, + propagation: { + accept_sampling_instruction:, + extractors:, + injectors: + } + } + } + ) + end + + describe 'steno logger context data' do + context 'when a valid tracing context was propagated via http headers to the cloud_controller' do + before do + configure_otel(['tracecontext'], []) + end + + it 'sets the trace_id and span_id of the tracing context as attributes in the steno logger' do + middlewares.call({ + 'HTTP_TRACEPARENT' => "00-#{trace_id}-#{span_id}-01" + }) + expect(Steno.config.context.data['b3_trace_id']).to eq(fake_app.parsed_trace_id) + expect(Steno.config.context.data['b3_span_id']).to eq(fake_app.parsed_span_id) + end + + it 'removes the trace_id and span_id from the steno logger context data when no tracing context was propagated' do + middlewares.call({}) + expect(Steno.config.context.data['b3_trace_id']).to be_nil + expect(Steno.config.context.data['b3_span_id']).to be_nil + end + end + + context 'when a root span was started' do + before do + configure_otel([], []) + end + + it 'sets the trace_id and span_id of the tracing context as attributes in the steno logger' do + middlewares.call({}) + expect(Steno.config.context.data['otel_trace_id']).to eq(fake_app.parsed_trace_id) + expect(Steno.config.context.data['otel_span_id']).not_to be_nil + end + end + end + + describe 'sampler' do + context 'when accept_sampling_instruction is set to true' do + it 'does use the ParentBased sampler' do + configure_otel([], [], sampling_ratio: 0, accept_sampling_instruction: true) + middlewares.call({}) + expect(OpenTelemetry.tracer_provider.sampler).to be_an_instance_of(OpenTelemetry::SDK::Trace::Samplers::ParentBased) + end + + context 'when sampling_ratio is set to 0' do + it 'does not sample the request' do + configure_otel([], [], sampling_ratio: 0, accept_sampling_instruction: true) + middlewares.call({}) + expect(fake_app.last_span_sampled).to be(false) + end + end + + context 'when sampling_ratio is set to 1' do + it 'samples the request' do + configure_otel([], [], sampling_ratio: 1, accept_sampling_instruction: true) + middlewares.call({}) + expect(fake_app.last_span_sampled).to be(true) + end + end + + context 'when sampling_ratio is set to 0.5' do + it 'samples the request' do + configure_otel([], [], sampling_ratio: 0.5, accept_sampling_instruction: true) + sampled_requests = 0 + 1000.times do + middlewares.call({}) + sampled_requests += 1 if fake_app.last_span_sampled + end + expect(sampled_requests).to be_within(50).of(500) + end + end + + context 'when sampling_ratio is out of bounds' do + it 'throws an exception on loading the configuration' do + expect { configure_otel([], [], sampling_ratio: 1.1, accept_sampling_instruction: true) }.to raise_error(ArgumentError) + expect { configure_otel([], [], sampling_ratio: -0.1, accept_sampling_instruction: true) }.to raise_error(ArgumentError) + end + end + end + + context 'when accept_sampling_instruction is set to false' do + it 'does use the TraceIdRatioBased sampler' do + configure_otel([], [], sampling_ratio: 0, accept_sampling_instruction: false) + middlewares.call({}) + expect(OpenTelemetry.tracer_provider.sampler).to be_an_instance_of(OpenTelemetry::SDK::Trace::Samplers::TraceIdRatioBased) + end + + context 'when sampling_ratio is set to 0' do + it 'does not sample the request' do + configure_otel([], [], sampling_ratio: 0, accept_sampling_instruction: false) + middlewares.call({}) + expect(fake_app.last_span_sampled).to be(false) + end + end + + context 'when sampling_ratio is set to 1' do + it 'samples the request' do + configure_otel([], [], sampling_ratio: 1, accept_sampling_instruction: false) + middlewares.call({}) + expect(fake_app.last_span_sampled).to be(true) + end + end + + context 'when sampling_ratio is set to 0.5' do + it 'samples the request' do + configure_otel([], [], sampling_ratio: 0.5, accept_sampling_instruction: false) + sampled_requests = 0 + 1000.times do + middlewares.call({}) + sampled_requests += 1 if fake_app.last_span_sampled + end + expect(sampled_requests).to be_within(50).of(500) + end + end + + context 'when sampling_ratio is out of bounds' do + it 'throws an exception on loading the configuration' do + expect { configure_otel([], [], sampling_ratio: 1.1, accept_sampling_instruction: false) }.to raise_error(ArgumentError) + expect { configure_otel([], [], sampling_ratio: -0.1, accept_sampling_instruction: false) }.to raise_error(ArgumentError) + end + end + end + end + + describe 'root span request related attributes' do + let(:tracer) { instance_double(OpenTelemetry::SDK::Trace::Tracer) } + + before do + configure_otel([], [], sampling_ratio: 1) + allow(OpenTelemetry.tracer_provider).to receive(:tracer).and_return(tracer) + allow(tracer).to receive(:in_span) + end + + context 'when the request contains the following headers' do + let(:rack_env) do + { + 'SERVER_SOFTWARE' => 'thin 1.8.2 codename Ruby Razor', + 'SERVER_NAME' => 'localhost', + 'rack.version' => [1, 0], + 'rack.multithread' => true, + 'rack.multiprocess' => false, + 'rack.run_once' => false, + 'REQUEST_METHOD' => 'POST', + 'REQUEST_PATH' => '/v3/security_groups', + 'PATH_INFO' => '/v3/security_groups', + 'REQUEST_URI' => '/v3/security_groups?name=test', + 'HTTP_VERSION' => 'HTTP/1.0', + 'HTTP_HOST' => 'localhost', + 'HTTP_X_REAL_IP' => '192.168.1.2', + 'HTTP_X_FORWARDED_FOR' => '192.168.1.2', + 'HTTP_CONNECTION' => 'close', + 'HTTP_USER_AGENT' => 'cf/8.7.1+9c81242.2023-06-15 (go1.20.5; arm64 darwin)', + 'HTTP_ACCEPT' => 'application/json', 'HTTP_ACCEPT_ENCODING' => 'gzip', + 'CONTENT_LENGTH' => '321', + 'CONTENT_TYPE' => 'application/json', + 'GATEWAY_INTERFACE' => 'CGI/1.2', + 'SERVER_PORT' => '80', + 'QUERY_STRING' => 'name=test', + 'SERVER_PROTOCOL' => 'HTTP/1.1', + 'rack.url_scheme' => 'http', + 'SCRIPT_NAME' => '', + 'REMOTE_ADDR' => '127.0.0.1' + } + end + let(:wanted_attributes) do + { + 'http.request.method' => 'POST', + 'url.path' => '/v3/security_groups', + 'url.scheme' => 'http', + 'url.query' => 'name=test', + 'url.full' => '/v3/security_groups?name=test', + 'http.host' => 'localhost', + 'user_agent.original' => 'cf/8.7.1+9c81242.2023-06-15 (go1.20.5; arm64 darwin)', + 'http.request.header.connection' => 'close', + 'http.request.header.version' => 'HTTP/1.0', + 'http.request.header.x_real_ip' => '192.168.1.2', + 'http.request.header.x_forwared_for' => '192.168.1.2', + 'http.request.header.accept' => 'application/json', + 'http.request.header.accept_encoding' => 'gzip', + 'http.request.body.size' => '321' + } + end + + it 'does set the correct attributes' do + middlewares.call(rack_env) + expect(tracer).to have_received(:in_span).exactly(1).times.with('POST: /v3/security_groups', attributes: wanted_attributes, kind: :server) + end + end + + context 'when the request has no headers' do + let(:wanted_attributes) do + { + 'http.request.method' => '', + 'url.path' => '', + 'url.scheme' => '', + 'url.query' => '', + 'url.full' => '', + 'http.host' => '', + 'user_agent.original' => '', + 'http.request.header.connection' => '', + 'http.request.header.version' => '', + 'http.request.header.x_real_ip' => '', + 'http.request.header.x_forwared_for' => '', + 'http.request.header.accept' => '', + 'http.request.header.accept_encoding' => '', + 'http.request.body.size' => '' + } + end + + it 'does set empty strings as attributes' do + middlewares.call({}) + expect(tracer).to have_received(:in_span).exactly(1).times.with('unknown', attributes: wanted_attributes, kind: :server) + end + end + end + + describe 'root span response related attributes' do + it 'does record the status code and response body size' do + span = instance_double(OpenTelemetry::Trace::Span) + allow_any_instance_of(OpenTelemetry::Trace::Tracer).to receive(:in_span).and_yield(span) + allow(span).to receive(:set_attribute) + + expect(span).to receive(:set_attribute).with('http.response.status_code', 200) + expect(span).to receive(:set_attribute).with('http.response.body.size', 20) + + middlewares.call({}) + end + end + + describe 'tracing secret/information redaction' do + let(:configurator) { double.as_null_object } + let(:tracer_provider) { double('TracerProvider', sampler: nil) } + + before do + allow(OpenTelemetry::SDK).to receive(:configure).and_yield(configurator) + allow(tracer_provider).to receive(:sampler=) + allow(OpenTelemetry).to receive(:tracer_provider).and_return(tracer_provider) + end + + context 'when redaction is not configured' do + it 'does propagate the :include redaction decision to the instrumentation' do + if defined?(::PG) # If postgres gem is loaded + expect(configurator).to receive(:use).with('OpenTelemetry::Instrumentation::PG', { db_statement: :include }) + else # If mysql2 gem is loaded + expect(configurator).to receive(:use).with('OpenTelemetry::Instrumentation::Mysql2', { db_statement: :include }) + end + configure_otel([], [], redact_db_statement: false) + end + end + + context 'when redaction is configured' do + it 'does propagate the :obfuscate redaction decision to the instrumentation' do + if defined?(::PG) # If postgres gem is loaded + expect(configurator).to receive(:use).with('OpenTelemetry::Instrumentation::PG', { db_statement: :obfuscate }) + else # If mysql2 gem is loaded + expect(configurator).to receive(:use).with('OpenTelemetry::Instrumentation::Mysql2', { db_statement: :obfuscate }) + end + configure_otel([], []) + end + end + end + + describe 'extractors behaviour in regards to received request headers' do + describe 'b3multi' do + before do + configure_otel(['b3multi'], []) + end + + it 'does parse the b3multi headers' do + middlewares.call( + { + 'HTTP_X_B3_TRACEID' => trace_id, + 'HTTP_X_B3_SPANID' => span_id, + 'HTTP_X_B3_SAMPLED' => '1', + 'HTTP_X_B3_PARENTSPANID' => parent_span_id + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.parsed_parent_span_id).to be_nil + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does not requre optional fields' do + middlewares.call( + { + 'HTTP_X_B3_TRACEID' => trace_id, + 'HTTP_X_B3_SPANID' => span_id, + 'HTTP_X_B3_SAMPLED' => '0' + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does not parse the b3multi headers when no b3multi extractor is configured' do + configure_otel([], []) + middlewares.call( + { + 'HTTP_X_B3_TRACEID' => trace_id, + 'HTTP_X_B3_SPANID' => span_id, + 'HTTP_X_B3_SAMPLED' => '1', + 'HTTP_X_B3_PARENTSPANID' => parent_span_id + } + ) + expect(fake_app.parsed_trace_id).to eq(fake_app.last_trace_id) + expect(fake_app.parsed_span_id).to eq(fake_app.last_span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'processes the b3single header despite b3multi is configured' do + middlewares.call( + { + 'HTTP_B3' => "#{trace_id}-#{span_id}-1-#{parent_span_id}" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'processes the b3single header without optional fields despite b3multi is configured' do + middlewares.call( + { + 'HTTP_B3' => "#{trace_id}-#{span_id}" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + describe 'the behaviour when the sampling header is set' do + context 'when accept_sampling_instruction is false' do + it 'does not enforce sampling when the sampling header is set to 1' do + configure_otel(['b3multi'], [], sampling_ratio: 0) + middlewares.call( + { + 'HTTP_X_B3_TRACEID' => trace_id, + 'HTTP_X_B3_SPANID' => span_id, + 'HTTP_X_B3_SAMPLED' => '1' + } + ) + expect(fake_app.last_span_sampled).to be(false) + end + + it 'does not skip sampling when the sampling header is set to 0' do + middlewares.call( + { + 'HTTP_X_B3_TRACEID' => trace_id, + 'HTTP_X_B3_SPANID' => span_id, + 'HTTP_X_B3_SAMPLED' => '0' + } + ) + expect(fake_app.last_span_sampled).to be(true) + end + end + + context 'when accept_sampling_instruction is true' do + it 'does force sampling when the sampling header is set to 1' do + configure_otel(['b3multi'], [], sampling_ratio: 0, accept_sampling_instruction: true) + middlewares.call( + { + 'HTTP_X_B3_TRACEID' => trace_id, + 'HTTP_X_B3_SPANID' => span_id, + 'HTTP_X_B3_SAMPLED' => '1' + } + ) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does prevent sampling when the sampling header is set to 0' do + configure_otel(['b3multi'], [], sampling_ratio: 1, accept_sampling_instruction: true) + middlewares.call( + { + 'HTTP_X_B3_TRACEID' => trace_id, + 'HTTP_X_B3_SPANID' => span_id, + 'HTTP_X_B3_SAMPLED' => '0' + } + ) + expect(fake_app.last_span_sampled).to be(false) + end + end + end + end + + describe 'b3' do + before do + configure_otel(['b3'], [], sampling_ratio: 1.0) + end + + it 'processes the b3 header when the b3 extractor is configured' do + middlewares.call( + { + 'HTTP_B3' => "#{trace_id}-#{span_id}-1-#{parent_span_id}" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'processes the b3 header without optional fields when the b3 extractor is configured' do + middlewares.call( + { + 'HTTP_B3' => "#{trace_id}-#{span_id}" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does not parse the b3 header when no b3 extractor is configured' do + configure_otel([], []) + middlewares.call( + { + 'HTTP_B3' => "#{trace_id}-#{span_id}-1-#{parent_span_id}" + } + ) + expect(fake_app.parsed_trace_id).to eq(fake_app.last_trace_id) + expect(fake_app.parsed_span_id).to eq(fake_app.last_span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does parse the b3multi headers despite b3 being configured' do + middlewares.call( + { + 'HTTP_X_B3_TRACEID' => trace_id, + 'HTTP_X_B3_SPANID' => span_id, + 'HTTP_X_B3_SAMPLED' => '1', + 'HTTP_X_B3_PARENTSPANID' => parent_span_id + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does parse the b3multi headers despite b3 being configured without optional fields' do + middlewares.call( + { + 'HTTP_X_B3_TRACEID' => trace_id, + 'HTTP_X_B3_SPANID' => span_id + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + describe 'the behaviour when the sampling header is set' do + context 'when accept_sampling_instruction is false' do + it 'does not enforce sampling when the sampling header is set to 1' do + configure_otel(['b3'], [], sampling_ratio: 0) + middlewares.call( + { 'HTTP_B3' => "#{trace_id}-#{span_id}-1" } + ) + expect(fake_app.last_span_sampled).to be(false) + end + + it 'does not skip sampling when the sampling header is set to 0' do + middlewares.call( + { 'HTTP_B3' => "#{trace_id}-#{span_id}-0" } + ) + expect(fake_app.last_span_sampled).to be(true) + end + end + + context 'when accept_sampling_instruction is true' do + it 'does force sampling when the sampling header is set to 1' do + configure_otel(['b3'], [], sampling_ratio: 0, accept_sampling_instruction: true) + middlewares.call( + { 'HTTP_B3' => "#{trace_id}-#{span_id}-1" } + ) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does prevent sampling when the sampling header is set to 0' do + configure_otel(['b3'], [], sampling_ratio: 1, accept_sampling_instruction: true) + middlewares.call( + { 'HTTP_B3' => "#{trace_id}-#{span_id}-0" } + ) + expect(fake_app.last_span_sampled).to be(false) + end + end + end + end + + describe 'tracecontext' do + before do + configure_otel(['tracecontext'], [], sampling_ratio: 1) + end + + it 'does parse tracecontext headers when a tracecontext extractor is configured' do + middlewares.call( + { + 'HTTP_TRACEPARENT' => "00-#{trace_id}-#{span_id}-01" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does not parse tracecontext headers when no tracecontext extractor is configured' do + configure_otel([], []) + middlewares.call( + { 'HTTP_TRACEPARENT' => "00-#{trace_id}-#{span_id}-01" } + ) + expect(fake_app.parsed_trace_id).to eq(fake_app.last_trace_id) + expect(fake_app.parsed_span_id).to eq(fake_app.last_span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + describe 'the behaviour when the sampling header is set' do + context 'when accept_sampling_instruction is false' do + it 'does not enforce sampling when the sampling header is set to 1' do + configure_otel(['tracecontext'], [], sampling_ratio: 0) + middlewares.call( + { 'HTTP_TRACEPARENT' => "00-#{trace_id}-#{span_id}-01" } + ) + expect(fake_app.last_span_sampled).to be(false) + end + + it 'does not skip sampling when the sampling header is set to 0' do + middlewares.call( + { 'HTTP_TRACEPARENT' => "00-#{trace_id}-#{span_id}-00" } + ) + expect(fake_app.last_span_sampled).to be(true) + end + end + + context 'when accept_sampling_instruction is true' do + it 'does force sampling when the sampling header is set to 1' do + configure_otel(['tracecontext'], [], sampling_ratio: 0, accept_sampling_instruction: true) + middlewares.call( + { 'HTTP_TRACEPARENT' => "00-#{trace_id}-#{span_id}-01" } + ) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does prevent sampling when the sampling header is set to 0' do + configure_otel(['tracecontext'], [], sampling_ratio: 1, accept_sampling_instruction: true) + middlewares.call( + { 'HTTP_TRACEPARENT' => "00-#{trace_id}-#{span_id}-00" } + ) + expect(fake_app.last_span_sampled).to be(false) + end + end + end + end + + describe 'jaeger' do + before do + configure_otel(['jaeger'], []) + end + + it 'does parse jaeger headers when a jaeger extractor is configured' do + middlewares.call( + { + 'HTTP_UBER_TRACE_ID' => "#{trace_id}:#{span_id}:0:1" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does not parse jaeger headers with only trace_id and span_id fields when a jaeger extractor is configured' do + middlewares.call( + { + 'HTTP_UBER_TRACE_ID' => "#{trace_id}:#{span_id}" + } + ) + expect(fake_app.parsed_trace_id).to eq(fake_app.last_trace_id) + expect(fake_app.parsed_span_id).to eq(fake_app.last_span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does not parse jaeger headers when no jaeger extractor is configured' do + configure_otel([], []) + middlewares.call( + { + 'HTTP_UBER_TRACE_ID' => "#{trace_id}:#{span_id}:0:1" + } + ) + expect(fake_app.parsed_trace_id).to eq(fake_app.last_trace_id) + expect(fake_app.parsed_span_id).to eq(fake_app.last_span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + describe 'the behaviour when the sampling header is set' do + context 'when accept_sampling_instruction is false' do + it 'does not enforce sampling when the sampling header is set to 1' do + configure_otel(['jaeger'], [], sampling_ratio: 0) + middlewares.call( + { 'HTTP_UBER_TRACE_ID' => "#{trace_id}:#{span_id}:0:1" } + ) + expect(fake_app.last_span_sampled).to be(false) + end + + it 'does not skip sampling when the sampling header is set to 0' do + middlewares.call( + { 'HTTP_UBER_TRACE_ID' => "#{trace_id}:#{span_id}:0:0" } + ) + expect(fake_app.last_span_sampled).to be(true) + end + end + + context 'when accept_sampling_instruction is true' do + it 'does force sampling when the sampling header is set to 1' do + configure_otel(['jaeger'], [], sampling_ratio: 0, accept_sampling_instruction: true) + middlewares.call( + { 'HTTP_UBER_TRACE_ID' => "#{trace_id}:#{span_id}:0:1" } + ) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does prevent sampling when the sampling header is set to 0' do + configure_otel(['jaeger'], [], sampling_ratio: 1, accept_sampling_instruction: true) + middlewares.call( + { 'HTTP_UBER_TRACE_ID' => "#{trace_id}:#{span_id}:0:0" } + ) + expect(fake_app.last_span_sampled).to be(false) + end + end + end + + describe 'baggage' do + it 'does parse baggage headers when a jaeger extractor is configured' do + middlewares.call( + { + 'HTTP_UBER_TRACE_ID' => "#{trace_id}:#{span_id}:0:1", + 'HTTP_UBERCTX_FOO' => 'bar' + } + ) + expect(fake_app.parsed_baggage_values['foo']).to eq('bar') + end + + it 'does not parse baggage headers when no tracing header exists' do + middlewares.call( + { + 'HTTP_UBERCTX-FOO' => 'bar' + } + ) + expect(fake_app.parsed_baggage_values).to eq({}) + end + + it 'does not parse baggage headers when no jaeger extractor is configured' do + configure_otel([], []) + middlewares.call( + { + 'HTTP_UBER_TRACE_ID' => "#{trace_id}:#{span_id}:0:1", + 'HTTP_UBERCTX-FOO' => 'bar' + } + ) + expect(fake_app.parsed_baggage_values).to eq({}) + end + end + end + + describe 'xray' do + before do + configure_otel(['xray'], []) + end + + it 'does parse xray headers when a xray extractor is configured' do + middlewares.call( + { + 'HTTP_X_AMZN_TRACE_ID' => "Root=1-#{trace_id[0...8]}-#{trace_id[8...]};Parent=#{span_id};Sampled=1" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does parse xray headers without optional fields when a xray extractor is configured' do + middlewares.call( + { + 'HTTP_X_AMZN_TRACE_ID' => "Root=1-#{trace_id[0...8]}-#{trace_id[8...]};Parent=#{span_id}" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id) + expect(fake_app.parsed_span_id).to eq(span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does not parse xray headers when no xray extractor is configured' do + configure_otel([], []) + middlewares.call( + { + 'HTTP_X_AMZN_TRACE_ID' => "Root=1-#{trace_id[0...8]}-#{trace_id[8...]};Parent=#{span_id};Sampled=1" + } + ) + expect(fake_app.parsed_trace_id).to eq(fake_app.last_trace_id) + expect(fake_app.parsed_span_id).to eq(fake_app.last_span_id) + expect(fake_app.last_span_sampled).to be(true) + end + + describe 'the behaviour when the sampling header is set' do + context 'when accept_sampling_instruction is false' do + it 'does not enforce sampling when the sampling header is set to 1' do + configure_otel(['xray'], [], sampling_ratio: 0) + middlewares.call( + { 'HTTP_X_AMZN_TRACE_ID' => "Root=1-#{trace_id[0...8]}-#{trace_id[8...]};Parent=#{span_id};Sampled=1" } + ) + expect(fake_app.last_span_sampled).to be(false) + end + + it 'does not skip sampling when the sampling header is set to 0' do + middlewares.call( + { 'HTTP_X_AMZN_TRACE_ID' => "Root=1-#{trace_id[0...8]}-#{trace_id[8...]};Parent=#{span_id};Sampled=0" } + ) + expect(fake_app.last_span_sampled).to be(true) + end + end + + context 'when accept_sampling_instruction is true' do + it 'does force sampling when the sampling header is set to 1' do + configure_otel(['xray'], [], sampling_ratio: 0, accept_sampling_instruction: true) + middlewares.call( + { 'HTTP_X_AMZN_TRACE_ID' => "Root=1-#{trace_id[0...8]}-#{trace_id[8...]};Parent=#{span_id};Sampled=1" } + ) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'does prevent sampling when the sampling header is set to 0' do + configure_otel(['xray'], [], sampling_ratio: 1, accept_sampling_instruction: true) + middlewares.call( + { 'HTTP_X_AMZN_TRACE_ID' => "Root=1-#{trace_id[0...8]}-#{trace_id[8...]};Parent=#{span_id};Sampled=0" } + ) + expect(fake_app.last_span_sampled).to be(false) + end + end + end + + describe 'baggage' do + it 'does not parse baggage headers when a xray extractor is configured, as this is not supported in ruby opentelemetry' do + middlewares.call( + { + 'HTTP_X_AMZN_TRACE_ID' => "Root=1-#{trace_id[0...8]}-#{trace_id[8...]};Parent=#{span_id};Sampled=1;foo=bar" + } + ) + expect(fake_app.parsed_baggage_values['segment']).to be_nil + end + end + end + + describe 'baggage' do + before do + configure_otel(%w[baggage], []) + end + + it 'parses the baggage header when the baggage header is present' do + middlewares.call( + { + 'HTTP_BAGGAGE' => 'foo=bar' + } + ) + expect(fake_app.parsed_baggage_values['foo']).to eq('bar') + end + + it 'does not parse the baggage header when no baggage extractor is configured' do + configure_otel(%w[], []) + middlewares.call( + { + 'HTTP_BAGGAGE' => 'foo=bar' + } + ) + expect(fake_app.parsed_baggage_values['foo']).to be_nil + end + end + + describe 'handling multiple extractors' do + # First Header of Propagation method is used for propagation; Second one is being ignored + let(:trace_id_1) { SecureRandom.hex(16) } + let(:span_id_1) { SecureRandom.hex(8) } + let(:trace_id_2) { SecureRandom.hex(16) } + let(:span_id_2) { SecureRandom.hex(8) } + + it 'uses the last configured extractor in the extractor config array tracecontext' do + configure_otel(%w[baggage jaeger tracecontext], []) + middlewares.call( + { + 'HTTP_TRACEPARENT' => "00-#{trace_id_2}-#{span_id_2}-01", + 'HTTP_UBER_TRACE_ID' => "#{trace_id_1}:#{span_id_1}:0:1" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id_2) + expect(fake_app.parsed_span_id).to eq(span_id_2) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'prefers baggage over the jaeger baggage extraction' do + configure_otel(%w[baggage b3 jaeger], []) + middlewares.call( + { + 'HTTP_B3' => "#{trace_id_2}-#{span_id_2}-1", + 'HTTP_UBERCX_FOO2' => 'bar2', + 'HTTP_UBER_TRACE_ID' => "#{trace_id_1}:#{span_id_1}:0:1", + 'HTTP_BAGGAGE' => 'foo1=bar1' + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id_1) + expect(fake_app.parsed_span_id).to eq(span_id_1) + expect(fake_app.last_span_sampled).to be(true) + expect(fake_app.parsed_baggage_values['foo1']).to eq('bar1') + expect(fake_app.parsed_baggage_values['foo2']).to be_nil + end + + it 'uses the last configured extractor in the extractor config array jaeger' do + configure_otel(%w[tracecontext jaeger], []) + middlewares.call( + { + 'HTTP_UBER_TRACE_ID' => "#{trace_id_1}:#{span_id_1}:0:1", + 'HTTP_TRACEPARENT' => "00-#{trace_id_2}-#{span_id_2}-01" + } + ) + expect(fake_app.parsed_trace_id).to eq(trace_id_1) + expect(fake_app.parsed_span_id).to eq(span_id_1) + expect(fake_app.last_span_sampled).to be(true) + end + + it 'honors the sampled flag of the last extractor' do + configure_otel(%w[tracecontext jaeger], [], accept_sampling_instruction: true) + middlewares.call( + { + 'HTTP_UBER_TRACE_ID' => "#{trace_id_1}:#{span_id_1}:0:1", + 'HTTP_TRACEPARENT' => "00-#{trace_id_2}-#{span_id_2}-00" + } + ) + expect(fake_app.last_span_sampled).to be(true) + end + end + end + + describe 'injectors behaviour in regards to the configuration' do + describe 'b3multi' do + it 'does inject the b3multi headers' do + configure_otel([], ['b3multi']) + middlewares.call({}) + + expect(WebMock).to have_requested(:get, 'http://fake.net_http.request/').times(2) + expect(WebMock).to have_requested(:get, 'http://fake.http_client.request/').times(1) + + requests = WebMock::RequestRegistry.instance.requested_signatures.hash.keys + + requests.each do |req| + expect(req.headers['X-B3-Sampled']).to eq(fake_app.last_span_sampled ? '1' : '0'), + "Expected Request: '#{req}' to have sampled flag: '#{fake_app.last_span_sampled ? '1' : '0'}' in the X-B3-Sampled header." + expect(req.headers['X-B3-Traceid']).to eq(fake_app.last_trace_id), + "Expected Request: '#{req}' to have trace id: '#{fake_app.last_trace_id}' in the X-B3-TraceId header." + expect(req.headers['X-B3-Spanid']).not_to be_nil, "Expected Request: '#{req}' to have the X-B3-SpanId header." + end + end + end + + describe 'b3' do + it 'does inject the b3 headers' do + configure_otel([], ['b3']) + middlewares.call({}) + + expect(WebMock).to have_requested(:get, 'http://fake.net_http.request/').times(2) + expect(WebMock).to have_requested(:get, 'http://fake.http_client.request/').times(1) + + requests = WebMock::RequestRegistry.instance.requested_signatures.hash.keys + + requests.each do |req| + expect(req.headers['B3']).not_to be_nil, "Expected Request: '#{req}' to have B3 header." + trace, span, sampled = req.headers['B3'].split('-') + expect(trace).to eq(fake_app.last_trace_id), "Expected Request: '#{req}' to have trace id: '#{fake_app.last_trace_id}' in the B3 header." + expect(span).not_to be_nil, "Expected Request: '#{req}' to have span id not nil in the B3 header." + expect(sampled).to eq(fake_app.last_span_sampled ? '1' : '0'), + "Expected Request: '#{req}' to have sampled flag: '#{fake_app.last_span_sampled ? '1' : '0'}' in the B3 header." + end + end + end + + describe 'tracecontext' do + it 'does inject the tracecontext headers' do + configure_otel([], ['tracecontext']) + middlewares.call({}) + + expect(WebMock).to have_requested(:get, 'http://fake.net_http.request/').times(2) + expect(WebMock).to have_requested(:get, 'http://fake.http_client.request/').times(1) + + requests = WebMock::RequestRegistry.instance.requested_signatures.hash.keys + requests.each do |req| + expect(req.headers['Traceparent']).not_to be_nil, "Expected Request: '#{req}' to have Traceparent header." + _, trace, span, sampled = req.headers['Traceparent'].split('-') + expect(trace).to eq(fake_app.last_trace_id), "Expected Request: '#{req}' to have trace id: '#{fake_app.last_trace_id}' in the Traceparent header." + expect(span).not_to be_nil, "Expected Request: '#{req}' to have span id not nil in the Traceparent header." + expect(sampled).to eq(fake_app.last_span_sampled ? '01' : '00'), + "Expected Request: '#{req}' to have sampled flag: '#{fake_app.last_span_sampled ? '01' : '00'}' in the Traceparent header." + end + end + end + + describe 'jaeger' do + it 'does inject the jaeger headers with baggage' do + configure_otel([], ['jaeger']) + middlewares.call({}) + + expect(WebMock).to have_requested(:get, 'http://fake.net_http.request/').times(2) + expect(WebMock).to have_requested(:get, 'http://fake.http_client.request/').times(1) + + requests = WebMock::RequestRegistry.instance.requested_signatures.hash.keys + requests.each do |req| + expect(req.headers['Uber-Trace-Id']).not_to be_nil, "Expected Request: '#{req}' to have Uber-Trace-Id header." + trace, span, _, sampled = req.headers['Uber-Trace-Id'].split(':') + expect(trace).to eq(fake_app.last_trace_id), "Expected Request: '#{req}' to have trace id: '#{fake_app.last_trace_id}' in the Uber-Trace-Id header." + expect(span).not_to be_nil, "Expected Request: '#{req}' to have span id not nil in the Uber-Trace-Id header." + expect(sampled).to eq(fake_app.last_span_sampled ? '1' : '0'), + "Expected Request: '#{req}' to have sampled flag: '#{fake_app.last_span_sampled ? '1' : '0'}' in the Uber-Trace-Id header." + expect(req.headers['Uberctx-Test']).to eq('bommel'), "Expected Request: '#{req}' to have the Uberctx-Test header with value 'bommel'." + end + end + end + + describe 'xray' do + it 'does inject the xray headers' do + configure_otel([], ['xray']) + middlewares.call({}) + + expect(WebMock).to have_requested(:get, 'http://fake.net_http.request/').times(2) + expect(WebMock).to have_requested(:get, 'http://fake.http_client.request/').times(1) + + requests = WebMock::RequestRegistry.instance.requested_signatures.hash.keys + requests.each do |req| + expect(req.headers['X-Amzn-Trace-Id']).not_to be_nil, "Expected Request: '#{req}' to have X-Amzn-Trace-Id header." + root, parent, sampled = req.headers['X-Amzn-Trace-Id'].split(';') + expect(root).to eq("Root=1-#{fake_app.last_trace_id[0...8]}-#{fake_app.last_trace_id[8...]}"), + "Expected Request: '#{req}' to have trace id: '#{fake_app.last_trace_id}' in the X-Amzn-Trace-Id header." + expect(parent.split('=')[1]).not_to be_nil, "Expected Request: '#{req}' to have span id in the X-Amzn-Trace-Id header." + expect(sampled).to eq("Sampled=#{fake_app.last_span_sampled ? '1' : '0'}"), + "Expected Request: '#{req}' to have sampled flag: '#{fake_app.last_span_sampled ? '1' : '0'}' in the X-Amzn-Trace-Id header." + end + end + end + + describe 'baggage' do + it 'does inject the baggage headers' do + configure_otel([], ['baggage']) + middlewares.call({}) + expected_headers = { + 'Baggage' => 'test=bommel' + } + expect(WebMock).to have_requested(:get, 'http://fake.net_http.request/').with(headers: expected_headers).times(2) + expect(WebMock).to have_requested(:get, 'http://fake.http_client.request/').with(headers: expected_headers).times(1) + end + end + + describe 'none' do + it 'does not inject headers when no injector is configured' do + configure_otel([], []) + middlewares.call({}) + expected_headers = { + 'X-B3-TraceId' => fake_app.last_trace_id + } + expect(WebMock).not_to have_requested(:get, 'http://fake.net_http.request/').with(headers: expected_headers) + expect(WebMock).not_to have_requested(:get, 'http://fake.http_client.request/').with(headers: expected_headers) + end + + it 'does not inject headers when the none injector is configured' do + configure_otel([], ['none']) + middlewares.call({}) + expected_headers = { + 'X-B3-TraceId' => fake_app.last_trace_id + } + expect(WebMock).not_to have_requested(:get, 'http://fake.net_http.request/').with(headers: expected_headers) + expect(WebMock).not_to have_requested(:get, 'http://fake.http_client.request/').with(headers: expected_headers) + end + end + + describe 'multiple injectors' do + it 'injects the headers of all configured injectors' do + configure_otel([], %w[b3multi b3 jaeger baggage]) + middlewares.call({}) + + expect(WebMock).to have_requested(:get, 'http://fake.net_http.request/').times(2) + expect(WebMock).to have_requested(:get, 'http://fake.http_client.request/').times(1) + + WebMock::RequestRegistry.instance.requested_signatures.hash.keys + + requests = WebMock::RequestRegistry.instance.requested_signatures.hash.keys + requests.each do |req| + # B3 Multi + expect(req.headers['X-B3-Spanid']).not_to be_nil, "Expected Request: '#{req}' to have X-B3-Spanid header." + expect(req.headers['X-B3-Traceid']).to eq(fake_app.last_trace_id), + "Expected Request: '#{req}' to have trace id: '#{fake_app.last_trace_id}' in the X-B3-TraceId header." + expect(req.headers['X-B3-Sampled']).to eq(fake_app.last_span_sampled ? '1' : '0'), + "Expected Request: '#{req}' to have sampled flag: '#{fake_app.last_span_sampled ? '1' : '0'}' in the X-B3-Sampled header." + # B3 + expect(req.headers['B3']).not_to be_nil, "Expected Request: '#{req}' to have B3 header." + trace, span, sampled = req.headers['B3'].split('-') + expect(trace).to eq(fake_app.last_trace_id), "Expected Request: '#{req}' to have trace id: '#{fake_app.last_trace_id}' in the B3 header." + expect(span).not_to be_nil, "Expected Request: '#{req}' to have span id not nil in the B3 header." + expect(sampled).to eq(fake_app.last_span_sampled ? '1' : '0'), + "Expected Request: '#{req}' to have sampled flag: '#{fake_app.last_span_sampled ? '1' : '0'}' in the B3 header." + # Jaeger + expect(req.headers['Uber-Trace-Id']).not_to be_nil, "Expected Request: '#{req}' to have Uber-Trace-Id header." + trace, span, _, sampled = req.headers['Uber-Trace-Id'].split(':') + expect(trace).to eq(fake_app.last_trace_id), "Expected Request: '#{req}' to have trace id: '#{fake_app.last_trace_id}' in the Uber-Trace-Id header." + expect(span).not_to be_nil, "Expected Request: '#{req}' to have span id not nil in the Uber-Trace-Id header." + expect(sampled).to eq(fake_app.last_span_sampled ? '1' : '0'), + "Expected Request: '#{req}' to have sampled flag: '#{fake_app.last_span_sampled ? '1' : '0'}' in the Uber-Trace-Id header." + expect(req.headers['Uberctx-Test']).to eq('bommel'), "Expected Request: '#{req}' to have Uberctx-Test header with value 'bommel'." + # Baggage + expect(req.headers['Baggage']).to eq('test=bommel'), "Expected Request: '#{req}' to have Baggage header with value 'foo=bommel'." + end + end + end + end + end + end +end diff --git a/spec/unit/middleware/zipkin_spec.rb b/spec/unit/middleware/zipkin_spec.rb deleted file mode 100644 index 71cb454542f..00000000000 --- a/spec/unit/middleware/zipkin_spec.rb +++ /dev/null @@ -1,94 +0,0 @@ -require 'spec_helper' -require 'zipkin' -require 'securerandom' - -module CloudFoundry - module Middleware - RSpec.describe Zipkin do - let(:middleware) { Zipkin.new(app) } - let(:app) { Zipkin::FakeApp.new } - - class Zipkin::FakeApp - attr_accessor :last_trace_id, :last_span_id, :last_env_input - - def call(env) - @last_trace_id = ::VCAP::Request.b3_trace_id - @last_span_id = ::VCAP::Request.b3_span_id - @last_env_input = env - [200, {}, 'a body'] - end - end - - describe 'handling the request' do - let(:trace_id) { SecureRandom.hex(8) } - let(:span_id) { SecureRandom.hex(8) } - let(:request_headers) do - { - 'HTTP_X_B3_TRACEID' => trace_id, - 'HTTP_X_B3_SPANID' => span_id - } - end - - context 'setting the trace headers in the logger' do - it 'has assigned it before passing the request' do - middleware.call(request_headers) - expect(app.last_trace_id).to eq trace_id - expect(app.last_span_id).to eq span_id - end - - it 'nils it out after the request has been processed' do - middleware.call(request_headers) - expect(::VCAP::Request.b3_trace_id).to be_nil - expect(::VCAP::Request.b3_span_id).to be_nil - end - end - - context 'when the Zipkin (B3) headers are passed in from outside' do - it 'includes it in b3.trace_id and b3.span_id' do - middleware.call(request_headers) - expect(app.last_env_input['b3.trace_id']).to eq trace_id - expect(app.last_env_input['b3.span_id']).to eq span_id - end - end - - context 'when the Zipkin (B3) headers are NOT passed in from outside' do - it 'does not include b3.trace_id and b3.span_id' do - middleware.call({}) - expect(app.last_env_input['b3.trace_id']).to be_nil - expect(app.last_env_input['b3.span_id']).to be_nil - end - end - end - - describe 'the response' do - let(:trace_id) { SecureRandom.hex(8) } - let(:span_id) { SecureRandom.hex(8) } - - context 'when the Zipkin (B3) headers are passed in' do - let(:request_headers) do - { - 'HTTP_X_B3_TRACEID' => trace_id, - 'HTTP_X_B3_SPANID' => span_id - } - end - - it 'is returned in the response' do - _, headers, = middleware.call(request_headers) - - expect(headers['X-B3-TraceId']).to eq trace_id - expect(headers['X-B3-SpanId']).to eq span_id - end - end - - context 'when the Zipkin (B3) headers are NOT passed in' do - it 'does not return any Zipkin (B3) headers' do - _, headers, = middleware.call({}) - - expect(headers['X-B3-TraceId']).to be_nil - expect(headers['X-B3-SpanId']).to be_nil - end - end - end - end - end -end