diff --git a/docs/GettingStarted.md b/docs/GettingStarted.md index 78a3984b6c6..88370a40c87 100644 --- a/docs/GettingStarted.md +++ b/docs/GettingStarted.md @@ -1562,7 +1562,7 @@ run app | `quantize.query.obfuscate.with` | Defines the string to replace obfuscated matches with. May be a String. Option must be nested inside the `query.obfuscate` option. | `''` | | `quantize.query.obfuscate.regex` | Defines the regex with which the query string will be redacted. May be a Regexp, or `:internal` to use the default internal Regexp, which redacts well-known sensitive data. Each match is redacted entirely by replacing it with `query.obfuscate.with`. Option must be nested inside the `query.obfuscate` option. | `:internal` | | `quantize.fragment` | Defines behavior for URL fragments. May be `:show` to show URL fragments, or `nil` to remove fragments. Option must be nested inside the `quantize` option. | `nil` | -| `request_queuing` | Track HTTP request time spent in the queue of the frontend server. See [HTTP request queuing](#http-request-queuing) for setup details. Set to `true` to enable. | `false` | +| `request_queuing` | Track HTTP request time spent in the queue of the frontend server. See [HTTP request queuing](#http-request-queuing) for setup details. | `false` | | `web_service_name` | Service name for frontend server request queuing spans. (e.g. `'nginx'`) | `'web-server'` | Deprecation notice: @@ -1639,7 +1639,7 @@ end | Key | Description | Default | | --- | ----------- | ------- | | `distributed_tracing` | Enables [distributed tracing](#distributed-tracing) so that this service trace is connected with a trace of another service if tracing headers are received | `true` | -| `request_queuing` | Track HTTP request time spent in the queue of the frontend server. See [HTTP request queuing](#http-request-queuing) for setup details. Set to `true` to enable. | `false` | +| `request_queuing` | Track HTTP request time spent in the queue of the frontend server. See [HTTP request queuing](#http-request-queuing) for setup details. | `false` | | `exception_controller` | Class or Module which identifies a custom exception controller class. Tracer provides improved error behavior when it can identify custom exception controllers. By default, without this option, it 'guesses' what a custom exception controller looks like. Providing this option aids this identification. | `nil` | | `middleware` | Add the trace middleware to the Rails application. Set to `false` if you don't want the middleware to load. | `true` | | `middleware_names` | Enables any short-circuited middleware requests to display the middleware name as a resource for the trace. | `false` | @@ -2479,7 +2479,14 @@ server { } ``` -Then you must enable the request queuing feature, by setting `request_queuing: true`, in the integration handling the request. For Rack-based applications, see the [documentation](#rack) for details. +Then you must enable the request queuing feature. The following options are available for the `:request_queuing` configuration: + +| Option | Description | +| ------------------ | ----------- | +| `:include_request` | A `http_server.queue` span will be the root span of a trace, including the total time spent processing the request *in addition* to the time spent waiting for the request to begin being processed. This is the behavior when the configuration is set to `true`. This is the selected configuration when set to `true`. | +| `:exclude_request` | A `http.proxy.request` span will be the root span of a trace, with the `http.proxy.queue` child span duration representing only the time spent waiting for the request to begin being processed. *This is an experimental feature!* | + +For Rack-based applications, see the [documentation](#rack) for details. ### Processing Pipeline diff --git a/integration/apps/rails-seven/config/initializers/datadog.rb b/integration/apps/rails-seven/config/initializers/datadog.rb index 6ae2019eb52..dc535267d53 100644 --- a/integration/apps/rails-seven/config/initializers/datadog.rb +++ b/integration/apps/rails-seven/config/initializers/datadog.rb @@ -11,7 +11,7 @@ if Datadog::DemoEnv.feature?('tracing') c.tracing.analytics.enabled = true if Datadog::DemoEnv.feature?('analytics') - c.tracing.instrument :rails, request_queuing: true + c.tracing.instrument :rails, request_queuing: :exclude_request c.tracing.instrument :redis, service_name: 'acme-redis' c.tracing.instrument :resque end diff --git a/lib/datadog/tracing/contrib/rack/ext.rb b/lib/datadog/tracing/contrib/rack/ext.rb index 95bf16278a4..cbb94a1dc29 100644 --- a/lib/datadog/tracing/contrib/rack/ext.rb +++ b/lib/datadog/tracing/contrib/rack/ext.rb @@ -11,10 +11,15 @@ module Ext ENV_ANALYTICS_ENABLED = 'DD_TRACE_RACK_ANALYTICS_ENABLED'.freeze ENV_ANALYTICS_SAMPLE_RATE = 'DD_TRACE_RACK_ANALYTICS_SAMPLE_RATE'.freeze RACK_ENV_REQUEST_SPAN = 'datadog.rack_request_span'.freeze + SPAN_HTTP_PROXY_REQUEST = 'http.proxy.request'.freeze + SPAN_HTTP_PROXY_QUEUE = 'http.proxy.queue'.freeze SPAN_HTTP_SERVER_QUEUE = 'http_server.queue'.freeze SPAN_REQUEST = 'rack.request'.freeze TAG_COMPONENT = 'rack'.freeze + TAG_COMPONENT_HTTP_PROXY = 'http_proxy'.freeze TAG_OPERATION_REQUEST = 'request'.freeze + TAG_OPERATION_HTTP_PROXY_REQUEST = 'request'.freeze + TAG_OPERATION_HTTP_PROXY_QUEUE = 'queue'.freeze TAG_OPERATION_HTTP_SERVER_QUEUE = 'queue'.freeze WEBSERVER_APP = 'webserver'.freeze DEFAULT_PEER_WEBSERVER_SERVICE_NAME = 'web-server'.freeze diff --git a/lib/datadog/tracing/contrib/rack/middlewares.rb b/lib/datadog/tracing/contrib/rack/middlewares.rb index 889d9ed07eb..6fb9f443cf6 100644 --- a/lib/datadog/tracing/contrib/rack/middlewares.rb +++ b/lib/datadog/tracing/contrib/rack/middlewares.rb @@ -35,22 +35,34 @@ def compute_queue_time(env) request_start = Contrib::Rack::QueueTime.get_request_start(env) return if request_start.nil? - frontend_span = Tracing.trace( - Ext::SPAN_HTTP_SERVER_QUEUE, - span_type: Tracing::Metadata::Ext::HTTP::TYPE_PROXY, - start_time: request_start, - service: configuration[:web_service_name] - ) - - # Tag this span as belonging to Rack - frontend_span.set_tag(Tracing::Metadata::Ext::TAG_COMPONENT, Ext::TAG_COMPONENT) - frontend_span.set_tag(Tracing::Metadata::Ext::TAG_OPERATION, Ext::TAG_OPERATION_HTTP_SERVER_QUEUE) - frontend_span.set_tag(Tracing::Metadata::Ext::TAG_KIND, Tracing::Metadata::Ext::SpanKind::TAG_SERVER) - - # Set peer service (so its not believed to belong to this app) - frontend_span.set_tag(Tracing::Metadata::Ext::TAG_PEER_SERVICE, configuration[:web_service_name]) - - frontend_span + case configuration[:request_queuing] + when true, :include_request # DEV: Switch `true` to `:exclude_request` in v2.0 + queue_span = trace_http_server(Ext::SPAN_HTTP_SERVER_QUEUE, start_time: request_start) + # Tag this span as belonging to Rack + queue_span.set_tag(Tracing::Metadata::Ext::TAG_COMPONENT, Ext::TAG_COMPONENT) + queue_span.set_tag(Tracing::Metadata::Ext::TAG_OPERATION, Ext::TAG_OPERATION_HTTP_SERVER_QUEUE) + queue_span.set_tag(Tracing::Metadata::Ext::TAG_KIND, Tracing::Metadata::Ext::SpanKind::TAG_SERVER) + queue_span + when :exclude_request + request_span = trace_http_server(Ext::SPAN_HTTP_PROXY_REQUEST, start_time: request_start) + request_span.set_tag(Tracing::Metadata::Ext::TAG_COMPONENT, Ext::TAG_COMPONENT_HTTP_PROXY) + request_span.set_tag(Tracing::Metadata::Ext::TAG_OPERATION, Ext::TAG_OPERATION_HTTP_PROXY_REQUEST) + request_span.set_tag(Tracing::Metadata::Ext::TAG_KIND, Tracing::Metadata::Ext::SpanKind::TAG_PROXY) + + queue_span = trace_http_server(Ext::SPAN_HTTP_PROXY_QUEUE, start_time: request_start) + + # Measure service stats + Contrib::Analytics.set_measured(queue_span) + + queue_span.set_tag(Tracing::Metadata::Ext::TAG_COMPONENT, Ext::TAG_COMPONENT_HTTP_PROXY) + queue_span.set_tag(Tracing::Metadata::Ext::TAG_OPERATION, Ext::TAG_OPERATION_HTTP_PROXY_QUEUE) + queue_span.set_tag(Tracing::Metadata::Ext::TAG_KIND, Tracing::Metadata::Ext::SpanKind::TAG_PROXY) + # finish the `queue` span now to record only the time spent *in queue*, + # excluding the time spent processing the request itself + queue_span.finish + + request_span + end end def call(env) @@ -242,6 +254,20 @@ def configuration Datadog.configuration.tracing[:rack] end + def trace_http_server(span_name, start_time:) + span = Tracing.trace( + span_name, + span_type: Tracing::Metadata::Ext::HTTP::TYPE_PROXY, + start_time: start_time, + service: configuration[:web_service_name] + ) + + # Set peer service (so its not believed to belong to this app) + span.set_tag(Tracing::Metadata::Ext::TAG_PEER_SERVICE, configuration[:web_service_name]) + + span + end + def parse_url(env, original_env) request_obj = ::Rack::Request.new(env) diff --git a/lib/datadog/tracing/metadata/ext.rb b/lib/datadog/tracing/metadata/ext.rb index ce17a62b45c..f6163eb546f 100644 --- a/lib/datadog/tracing/metadata/ext.rb +++ b/lib/datadog/tracing/metadata/ext.rb @@ -166,6 +166,7 @@ module SQL # @public_api module SpanKind + TAG_PROXY = 'proxy' TAG_SERVER = 'server' TAG_CLIENT = 'client' TAG_PRODUCER = 'producer' diff --git a/spec/datadog/tracing/contrib/rack/configuration_spec.rb b/spec/datadog/tracing/contrib/rack/configuration_spec.rb index 252a642af16..05ca5ca6b0e 100644 --- a/spec/datadog/tracing/contrib/rack/configuration_spec.rb +++ b/spec/datadog/tracing/contrib/rack/configuration_spec.rb @@ -68,9 +68,8 @@ let(:queue_value) { nil } end - shared_examples_for 'a Rack request with queuing' do - let(:queue_span) { spans.first } - let(:rack_span) { spans.last } + shared_examples_for 'a Rack request with queuing including the request' do + let(:configuration_options) { super().merge(request_queuing: :include_request) } it 'produces a queued Rack trace' do is_expected.to be_ok @@ -79,17 +78,19 @@ expect(spans).to have(2).items + server_queue_span = spans[0] + rack_span = spans[1] + web_service_name = Datadog.configuration.tracing[:rack][:web_service_name] - expect(queue_span.name).to eq('http_server.queue') - expect(queue_span.span_type).to eq('proxy') - expect(queue_span.service).to eq(web_service_name) - expect(queue_span.start_time.to_i).to eq(queue_time) - expect(queue_span.get_tag(Datadog::Core::Runtime::Ext::TAG_LANG)).to be_nil - expect(queue_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_PEER_SERVICE)).to eq(web_service_name) - expect(queue_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_COMPONENT)) - .to eq('rack') - expect(queue_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_OPERATION)) - .to eq('queue') + + expect(server_queue_span.name).to eq('http_server.queue') + expect(server_queue_span.span_type).to eq('proxy') + expect(server_queue_span.service).to eq(web_service_name) + expect(server_queue_span.start_time.to_i).to eq(queue_time) + expect(server_queue_span.get_tag(Datadog::Core::Runtime::Ext::TAG_LANG)).to be_nil + expect(server_queue_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_PEER_SERVICE)).to eq(web_service_name) + expect(server_queue_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_COMPONENT)).to eq('rack') + expect(server_queue_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_OPERATION)).to eq('queue') expect(rack_span.name).to eq('rack.request') expect(rack_span.span_type).to eq('web') @@ -99,12 +100,58 @@ expect(rack_span.get_tag('http.status_code')).to eq('200') expect(rack_span.get_tag('http.url')).to eq('/') expect(rack_span.status).to eq(0) - expect(rack_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_COMPONENT)) - .to eq('rack') - expect(rack_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_OPERATION)) - .to eq('request') + expect(rack_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_COMPONENT)).to eq('rack') + expect(rack_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_OPERATION)).to eq('request') + expect(rack_span.parent_id).to eq(server_queue_span.span_id) + end + end + + shared_examples_for 'a Rack request with queuing excluding the request' do + let(:configuration_options) { super().merge(request_queuing: :exclude_request) } + + it 'produces a queued Rack trace' do + is_expected.to be_ok + + expect(trace.resource).to eq('GET 200') + + expect(spans).to have(3).items + + server_request_span = spans[1] + server_queue_span = spans[0] + rack_span = spans[2] + + web_service_name = Datadog.configuration.tracing[:rack][:web_service_name] + + expect(server_request_span.name).to eq('http.proxy.request') + expect(server_request_span.span_type).to eq('proxy') + expect(server_request_span.service).to eq(web_service_name) + expect(server_request_span.start_time.to_i).to eq(queue_time) + expect(server_request_span.get_tag(Datadog::Core::Runtime::Ext::TAG_LANG)).to be_nil + expect(server_request_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_PEER_SERVICE)).to eq(web_service_name) + expect(server_request_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_COMPONENT)).to eq('http_proxy') + expect(server_request_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_OPERATION)).to eq('request') + + expect(server_queue_span.name).to eq('http.proxy.queue') + expect(server_queue_span.span_type).to eq('proxy') + expect(server_queue_span.service).to eq(web_service_name) + expect(server_queue_span.start_time.to_i).to eq(queue_time) + expect(server_queue_span.get_tag(Datadog::Core::Runtime::Ext::TAG_LANG)).to be_nil + expect(server_queue_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_PEER_SERVICE)).to eq(web_service_name) + expect(server_queue_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_COMPONENT)).to eq('http_proxy') + expect(server_queue_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_OPERATION)).to eq('queue') + expect(server_queue_span.parent_id).to eq(server_request_span.span_id) - expect(queue_span.span_id).to eq(rack_span.parent_id) + expect(rack_span.name).to eq('rack.request') + expect(rack_span.span_type).to eq('web') + expect(rack_span.service).to eq(Datadog.configuration.service) + expect(rack_span.resource).to eq('GET 200') + expect(rack_span.get_tag('http.method')).to eq('GET') + expect(rack_span.get_tag('http.status_code')).to eq('200') + expect(rack_span.get_tag('http.url')).to eq('/') + expect(rack_span.status).to eq(0) + expect(rack_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_COMPONENT)).to eq('rack') + expect(rack_span.get_tag(Datadog::Tracing::Metadata::Ext::TAG_OPERATION)).to eq('request') + expect(rack_span.parent_id).to eq(server_request_span.span_id) end end @@ -135,7 +182,7 @@ end context 'when enabled' do - let(:configuration_options) { super().merge(request_queuing: true) } + let(:configuration_options) { super().merge(request_queuing: :exclude_request) } context 'and a request is received' do include_context 'an incoming HTTP request' @@ -145,15 +192,29 @@ let(:queue_header) { 'X-Request-Start' } end - it_behaves_like 'a Rack request with queuing' + it_behaves_like 'a Rack request with queuing including the request' + it_behaves_like 'a Rack request with queuing excluding the request' context 'given a custom web service name' do let(:configuration_options) { super().merge(web_service_name: web_service_name) } let(:web_service_name) { 'nginx' } - it_behaves_like 'a Rack request with queuing' do + it_behaves_like 'a Rack request with queuing including the request' do + it 'sets the custom service name' do + is_expected.to be_ok + + queue_span = spans.find { |s| s.name == Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_SERVER_QUEUE } + + expect(queue_span.service).to eq(web_service_name) + end + end + + it_behaves_like 'a Rack request with queuing excluding the request' do it 'sets the custom service name' do is_expected.to be_ok + + queue_span = spans.find { |s| s.name == Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_PROXY_QUEUE } + expect(queue_span.service).to eq(web_service_name) end end @@ -165,7 +226,8 @@ let(:queue_header) { 'X-Queue-Start' } end - it_behaves_like 'a Rack request with queuing' + it_behaves_like 'a Rack request with queuing including the request' + it_behaves_like 'a Rack request with queuing excluding the request' end # Ensure a queuing Span is NOT created if there is a clock skew diff --git a/spec/datadog/tracing/contrib/rack/distributed_spec.rb b/spec/datadog/tracing/contrib/rack/distributed_spec.rb index 34f9fd19564..255b0d14764 100644 --- a/spec/datadog/tracing/contrib/rack/distributed_spec.rb +++ b/spec/datadog/tracing/contrib/rack/distributed_spec.rb @@ -89,29 +89,64 @@ include_context 'distributed tracing headers' it_behaves_like 'a Rack request with distributed tracing' - context 'and request_queuing is enabled' do - let(:rack_options) { super().merge(request_queuing: true, web_service_name: web_service_name) } + context 'and request_queuing is enabled including the request time' do + let(:rack_options) { super().merge(request_queuing: :include_request, web_service_name: web_service_name) } let(:web_service_name) { 'frontend_web_server' } - let(:server_span) { spans.first } - let(:rack_span) { spans.last } - before do header 'X-Request-Start', "t=#{Time.now.to_f}" end it 'contains a request_queuing span that belongs to the distributed trace' do is_expected.to be_ok + + expect(trace.sampling_priority).to eq(sampling_priority) + expect(spans).to have(2).items - expect(server_span.name).to eq('http_server.queue') - expect(server_span.trace_id).to eq(trace_id) - expect(server_span.parent_id).to eq(parent_id) + server_queue_span = spans[0] + rack_span = spans[1] + + expect(server_queue_span.name).to eq('http_server.queue') + expect(server_queue_span.trace_id).to eq(trace_id) + expect(server_queue_span.parent_id).to eq(parent_id) + + expect(rack_span.name).to eq('rack.request') + expect(rack_span.trace_id).to eq(trace_id) + expect(rack_span.parent_id).to eq(server_queue_span.span_id) + end + end + + context 'and request_queuing is enabled excluding the request time' do + let(:rack_options) { super().merge(request_queuing: :exclude_request, web_service_name: web_service_name) } + let(:web_service_name) { 'frontend_web_server' } + + before do + header 'X-Request-Start', "t=#{Time.now.to_f}" + end + + it 'contains request and request_queuing spans that belongs to the distributed trace' do + is_expected.to be_ok + expect(trace.sampling_priority).to eq(sampling_priority) + expect(spans).to have(3).items + + server_request_span = spans[1] + server_queue_span = spans[0] + rack_span = spans[2] + + expect(server_request_span.name).to eq('http.proxy.request') + expect(server_request_span.trace_id).to eq(trace_id) + expect(server_request_span.parent_id).to eq(parent_id) + + expect(server_queue_span.name).to eq('http.proxy.queue') + expect(server_queue_span.trace_id).to eq(trace_id) + expect(server_queue_span.parent_id).to eq(server_request_span.span_id) + expect(rack_span.name).to eq('rack.request') expect(rack_span.trace_id).to eq(trace_id) - expect(rack_span.parent_id).to eq(server_span.span_id) + expect(rack_span.parent_id).to eq(server_request_span.span_id) end end end diff --git a/spec/datadog/tracing/contrib/rack/integration_test_spec.rb b/spec/datadog/tracing/contrib/rack/integration_test_spec.rb index 3bdc2aa91c7..06c82f53a5e 100644 --- a/spec/datadog/tracing/contrib/rack/integration_test_spec.rb +++ b/spec/datadog/tracing/contrib/rack/integration_test_spec.rb @@ -297,7 +297,6 @@ end context 'when `request_queuing` enabled' do - let(:rack_options) { { request_queuing: true } } let(:routes) do proc do map '/request_queuing_enabled' do @@ -306,7 +305,9 @@ end end - describe 'GET request with `HTTP_X_REQUEST_START` header' do + describe 'when request queueing includes the request time' do + let(:rack_options) { { request_queuing: :include_request } } + it 'creates web_server_span and rack span' do get 'request_queuing_enabled', nil, @@ -316,20 +317,72 @@ expect(spans).to have(2).items - web_server_span = spans.find { |s| s.name == Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_SERVER_QUEUE } - rack_span = spans.find { |s| s.name == Datadog::Tracing::Contrib::Rack::Ext::SPAN_REQUEST } - - expect(web_server_span).to be_root_span - expect(web_server_span.span_type).to eq('proxy') - expect(web_server_span.service).to eq('web-server') - expect(web_server_span.resource).to eq('http_server.queue') - expect(web_server_span.get_tag('component')).to eq('rack') - expect(web_server_span.get_tag('operation')).to eq('queue') - expect(web_server_span.get_tag('peer.service')).to eq('web-server') - expect(web_server_span.status).to eq(0) - expect(web_server_span.get_tag('span.kind')) - .to eq('server') + server_queue_span = spans[0] + rack_span = spans[1] + + expect(server_queue_span).to be_root_span + expect(server_queue_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_SERVER_QUEUE) + expect(server_queue_span.span_type).to eq('proxy') + expect(server_queue_span.service).to eq('web-server') + expect(server_queue_span.resource).to eq('http_server.queue') + expect(server_queue_span.get_tag('component')).to eq('rack') + expect(server_queue_span.get_tag('operation')).to eq('queue') + expect(server_queue_span.get_tag('peer.service')).to eq('web-server') + expect(server_queue_span.status).to eq(0) + expect(server_queue_span.get_tag('span.kind')).to eq('server') + + expect(rack_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_REQUEST) + expect(rack_span.span_type).to eq('web') + expect(rack_span.service).to eq(tracer.default_service) + expect(rack_span.resource).to eq('GET 200') + expect(rack_span.get_tag('http.method')).to eq('GET') + expect(rack_span.get_tag('http.status_code')).to eq('200') + expect(rack_span.status).to eq(0) + expect(rack_span.get_tag('component')).to eq('rack') + expect(rack_span.get_tag('operation')).to eq('request') + expect(rack_span.get_tag('span.kind')).to eq('server') + end + end + + describe 'when request queueing excludes the request time' do + let(:rack_options) { { request_queuing: :exclude_request } } + + it 'creates web_server_span and rack span' do + get 'request_queuing_enabled', + nil, + { Datadog::Tracing::Contrib::Rack::QueueTime::REQUEST_START => "t=#{Time.now.to_f}" } + + expect(trace.resource).to eq('GET 200') + + expect(spans).to have(3).items + server_request_span = spans[1] + server_queue_span = spans[0] + rack_span = spans[2] + + expect(server_request_span).to be_root_span + expect(server_request_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_PROXY_REQUEST) + expect(server_request_span.span_type).to eq('proxy') + expect(server_request_span.service).to eq('web-server') + expect(server_request_span.resource).to eq('http.proxy.request') + expect(server_request_span.get_tag('component')).to eq('http_proxy') + expect(server_request_span.get_tag('operation')).to eq('request') + expect(server_request_span.get_tag('peer.service')).to eq('web-server') + expect(server_request_span.status).to eq(0) + expect(server_request_span.get_tag('span.kind')).to eq('proxy') + + expect(server_queue_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_PROXY_QUEUE) + expect(server_queue_span.span_type).to eq('proxy') + expect(server_queue_span.service).to eq('web-server') + expect(server_queue_span.resource).to eq('http.proxy.queue') + expect(server_queue_span.get_tag('component')).to eq('http_proxy') + expect(server_queue_span.get_tag('operation')).to eq('queue') + expect(server_queue_span.get_tag('peer.service')).to eq('web-server') + expect(server_queue_span.status).to eq(0) + expect(server_queue_span.get_tag('span.kind')).to eq('proxy') + expect(server_queue_span).to be_measured + + expect(rack_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_REQUEST) expect(rack_span.span_type).to eq('web') expect(rack_span.service).to eq(tracer.default_service) expect(rack_span.resource).to eq('GET 200') @@ -338,8 +391,7 @@ expect(rack_span.status).to eq(0) expect(rack_span.get_tag('component')).to eq('rack') expect(rack_span.get_tag('operation')).to eq('request') - expect(rack_span.get_tag('span.kind')) - .to eq('server') + expect(rack_span.get_tag('span.kind')).to eq('server') end end end @@ -562,8 +614,8 @@ end end - context 'when `request_queuing` enabled and trace resource overwritten by nested app' do - let(:rack_options) { { request_queuing: true } } + context 'when `request_queuing` enabled with `:include_request` and trace resource overwritten by nested app' do + let(:rack_options) { { request_queuing: :include_request } } let(:routes) do proc do map '/resource_override' do @@ -580,7 +632,7 @@ end end - it 'creates a web_server_span and rack span with resource overriden' do + it 'creates a web_server span and rack span with resource overriden' do get '/resource_override', nil, { Datadog::Tracing::Contrib::Rack::QueueTime::REQUEST_START => "t=#{Time.now.to_f}" } @@ -589,20 +641,92 @@ expect(spans).to have(3).items - web_server_span = spans.find { |s| s.name == Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_SERVER_QUEUE } - rack_span = spans.find { |s| s.name == Datadog::Tracing::Contrib::Rack::Ext::SPAN_REQUEST } - nested_app_span = spans.find { |s| s.name == 'nested_app' } + server_queue_span = spans[0] + rack_span = spans[2] + nested_app_span = spans[1] + + expect(server_queue_span).to be_root_span + expect(server_queue_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_SERVER_QUEUE) + expect(server_queue_span.span_type).to eq('proxy') + expect(server_queue_span.service).to eq('web-server') + expect(server_queue_span.resource).to eq('http_server.queue') + expect(server_queue_span.get_tag('component')).to eq('rack') + expect(server_queue_span.get_tag('operation')).to eq('queue') + expect(server_queue_span.get_tag('peer.service')).to eq('web-server') + expect(server_queue_span.status).to eq(0) + expect(server_queue_span.get_tag('span.kind')).to eq('server') + + expect(rack_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_REQUEST) + expect(rack_span.span_type).to eq('web') + expect(rack_span.service).to eq(tracer.default_service) + expect(rack_span.resource).to eq('UserController#show') + expect(rack_span.get_tag('http.method')).to eq('GET') + expect(rack_span.get_tag('http.status_code')).to eq('200') + expect(rack_span.status).to eq(0) + expect(rack_span.get_tag('component')).to eq('rack') + expect(rack_span.get_tag('operation')).to eq('request') + expect(rack_span.get_tag('span.kind')).to eq('server') + + expect(nested_app_span.name).to eq('nested_app') + expect(nested_app_span.resource).to eq('UserController#show') + end + end - expect(web_server_span).to be_root_span - expect(web_server_span.span_type).to eq('proxy') - expect(web_server_span.service).to eq('web-server') - expect(web_server_span.resource).to eq('http_server.queue') - expect(web_server_span.get_tag('component')).to eq('rack') - expect(web_server_span.get_tag('operation')).to eq('queue') - expect(web_server_span.get_tag('peer.service')).to eq('web-server') - expect(web_server_span.status).to eq(0) - expect(web_server_span.get_tag('span.kind')).to eq('server') + context 'when `request_queuing` enabled with `:exclude_request` and trace resource overwritten by nested app' do + let(:rack_options) { { request_queuing: :exclude_request } } + let(:routes) do + proc do + map '/resource_override' do + run( + proc do |_env| + Datadog::Tracing.trace('nested_app', resource: 'UserController#show') do |span_op, trace_op| + trace_op.resource = span_op.resource + + [200, { 'Content-Type' => 'text/html' }, ['OK']] + end + end + ) + end + end + end + + it 'creates 2 web_server spans and rack span with resource overriden' do + get '/resource_override', + nil, + { Datadog::Tracing::Contrib::Rack::QueueTime::REQUEST_START => "t=#{Time.now.to_f}" } + + expect(trace.resource).to eq('UserController#show') + expect(spans).to have(4).items + + server_request_span = spans[1] + server_queue_span = spans[0] + rack_span = spans[3] + nested_app_span = spans[2] + + expect(server_request_span).to be_root_span + expect(server_request_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_PROXY_REQUEST) + expect(server_request_span.span_type).to eq('proxy') + expect(server_request_span.service).to eq('web-server') + expect(server_request_span.resource).to eq('http.proxy.request') + expect(server_request_span.get_tag('component')).to eq('http_proxy') + expect(server_request_span.get_tag('operation')).to eq('request') + expect(server_request_span.get_tag('peer.service')).to eq('web-server') + expect(server_request_span.status).to eq(0) + expect(server_request_span.get_tag('span.kind')).to eq('proxy') + + expect(server_queue_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_HTTP_PROXY_QUEUE) + expect(server_queue_span.span_type).to eq('proxy') + expect(server_queue_span.service).to eq('web-server') + expect(server_queue_span.resource).to eq('http.proxy.queue') + expect(server_queue_span.get_tag('component')).to eq('http_proxy') + expect(server_queue_span.get_tag('operation')).to eq('queue') + expect(server_queue_span.get_tag('peer.service')).to eq('web-server') + expect(server_queue_span.status).to eq(0) + expect(server_queue_span.get_tag('span.kind')).to eq('proxy') + expect(server_queue_span).to be_measured + + expect(rack_span.name).to eq(Datadog::Tracing::Contrib::Rack::Ext::SPAN_REQUEST) expect(rack_span.span_type).to eq('web') expect(rack_span.service).to eq(tracer.default_service) expect(rack_span.resource).to eq('UserController#show') @@ -613,6 +737,7 @@ expect(rack_span.get_tag('operation')).to eq('request') expect(rack_span.get_tag('span.kind')).to eq('server') + expect(nested_app_span.name).to eq('nested_app') expect(nested_app_span.resource).to eq('UserController#show') end end