Adds inter-service OpenTracing propagation

This change allows the GitLab rails and sidekiq components to receive
tracing spans from upstream services such as Workhorse and pass these
spans on to downstream services including Gitaly and Sidekiq.

This change will also emit traces for incoming and outgoing requests
using the propagated trace information. This will allow operators and
engineers to view traces across the Workhorse, GitLab Rails, Sidekiq and
Gitaly components.

Additional intra-service instrumentation will be added in future
changes.

.rubocop.yml

@@ -143,6 +143,7 @@ Naming/FileName:
     - XMPP
     - XSRF
     - XSS
+    - GRPC
 
 # GitLab ###################################################################
 

changelogs/unreleased/an-opentracing-propagation.yml

@@ -0,0 +1,5 @@
+---
+title: Adds inter-service OpenTracing propagation
+merge_request: 24239
+author:
+type: other

config/initializers/tracing.rb

@@ -3,6 +3,26 @@
 if Gitlab::Tracing.enabled?
   require 'opentracing'
 
+  Rails.application.configure do |config|
+    config.middleware.insert_after Gitlab::Middleware::CorrelationId, ::Gitlab::Tracing::RackMiddleware
+  end
+
+  # Instrument the Sidekiq client
+  Sidekiq.configure_client do |config|
+    config.client_middleware do |chain|
+      chain.add Gitlab::Tracing::Sidekiq::ClientMiddleware
+    end
+  end
+
+  # Instrument Sidekiq server calls when running Sidekiq server
+  if Sidekiq.server?
+    Sidekiq.configure_server do |config|
+      config.server_middleware do |chain|
+        chain.add Gitlab::Tracing::Sidekiq::ServerMiddleware
+      end
+    end
+  end
+
   # In multi-processed clustered architectures (puma, unicorn) don't
   # start tracing until the worker processes are spawned. This works
   # around issues when the opentracing implementation spawns threads

lib/gitlab/gitaly_client.rb

@@ -52,11 +52,18 @@ module Gitlab
           klass = stub_class(name)
           addr = stub_address(storage)
           creds = stub_creds(storage)
-          klass.new(addr, creds)
+          klass.new(addr, creds, interceptors: interceptors)
         end
       end
     end
 
+    def self.interceptors
+      return [] unless Gitlab::Tracing.enabled?
+
+      [Gitlab::Tracing::GRPCInterceptor.instance]
+    end
+    private_class_method :interceptors
+
     def self.stub_cert_paths
       cert_paths = Dir["#{OpenSSL::X509::DEFAULT_CERT_DIR}/*"]
       cert_paths << OpenSSL::X509::DEFAULT_CERT_FILE if File.exist? OpenSSL::X509::DEFAULT_CERT_FILE

lib/gitlab/tracing/common.rb

@@ -0,0 +1,59 @@
+# frozen_string_literal: true
+
+module Gitlab
+  module Tracing
+    module Common
+      def tracer
+        OpenTracing.global_tracer
+      end
+
+      # Convience method for running a block with a span
+      def in_tracing_span(operation_name:, tags:, child_of: nil)
+        scope = tracer.start_active_span(
+          operation_name,
+          child_of: child_of,
+          tags: tags
+        )
+        span = scope.span
+
+        # Add correlation details to the span if we have them
+        correlation_id = Gitlab::CorrelationId.current_id
+        if correlation_id
+          span.set_tag('correlation_id', correlation_id)
+        end
+
+        begin
+          yield span
+        rescue => e
+          log_exception_on_span(span, e)
+          raise e
+        ensure
+          scope.close
+        end
+      end
+
+      def log_exception_on_span(span, exception)
+        span.set_tag('error', true)
+        span.log_kv(kv_tags_for_exception(exception))
+      end
+
+      def kv_tags_for_exception(exception)
+        case exception
+        when Exception
+          {
+            'event':      'error',
+            'error.kind': exception.class.to_s,
+            'message':    Gitlab::UrlSanitizer.sanitize(exception.message),
+            'stack':      exception.backtrace.join("\n")
+          }
+        else
+          {
+            'event':        'error',
+            'error.kind':   exception.class.to_s,
+            'error.object': Gitlab::UrlSanitizer.sanitize(exception.to_s)
+          }
+        end
+      end
+    end
+  end
+end

lib/gitlab/tracing/grpc_interceptor.rb

@@ -0,0 +1,54 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+require 'grpc'
+
+module Gitlab
+  module Tracing
+    class GRPCInterceptor < GRPC::ClientInterceptor
+      include Common
+      include Singleton
+
+      def request_response(request:, call:, method:, metadata:)
+        wrap_with_tracing(method, 'unary', metadata) do
+          yield
+        end
+      end
+
+      def client_streamer(requests:, call:, method:, metadata:)
+        wrap_with_tracing(method, 'client_stream', metadata) do
+          yield
+        end
+      end
+
+      def server_streamer(request:, call:, method:, metadata:)
+        wrap_with_tracing(method, 'server_stream', metadata) do
+          yield
+        end
+      end
+
+      def bidi_streamer(requests:, call:, method:, metadata:)
+        wrap_with_tracing(method, 'bidi_stream', metadata) do
+          yield
+        end
+      end
+
+      private
+
+      def wrap_with_tracing(method, grpc_type, metadata)
+        tags = {
+          'component' =>  'grpc',
+          'span.kind' =>  'client',
+          'grpc.method' => method,
+          'grpc.type' =>   grpc_type
+        }
+
+        in_tracing_span(operation_name: "grpc:#{method}", tags: tags) do |span|
+          OpenTracing.inject(span.context, OpenTracing::FORMAT_TEXT_MAP, metadata)
+
+          yield
+        end
+      end
+    end
+  end
+end

lib/gitlab/tracing/rack_middleware.rb

@@ -0,0 +1,46 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+
+module Gitlab
+  module Tracing
+    class RackMiddleware
+      include Common
+
+      REQUEST_METHOD = 'REQUEST_METHOD'
+
+      def initialize(app)
+        @app = app
+      end
+
+      def call(env)
+        method = env[REQUEST_METHOD]
+
+        context = tracer.extract(OpenTracing::FORMAT_RACK, env)
+        tags = {
+          'component' =>   'rack',
+          'span.kind' =>   'server',
+          'http.method' => method,
+          'http.url' =>    self.class.build_sanitized_url_from_env(env)
+        }
+
+        in_tracing_span(operation_name: "http:#{method}", child_of: context, tags: tags) do |span|
+          @app.call(env).tap do |status_code, _headers, _body|
+            span.set_tag('http.status_code', status_code)
+          end
+        end
+      end
+
+      # Generate a sanitized (safe) request URL from the rack environment
+      def self.build_sanitized_url_from_env(env)
+        request = ActionDispatch::Request.new(env)
+
+        original_url = request.original_url
+        uri = URI.parse(original_url)
+        uri.query = request.filtered_parameters.to_query if uri.query.present?
+
+        uri.to_s
+      end
+    end
+  end
+end

lib/gitlab/tracing/sidekiq/client_middleware.rb

@@ -0,0 +1,26 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+
+module Gitlab
+  module Tracing
+    module Sidekiq
+      class ClientMiddleware
+        include SidekiqCommon
+
+        SPAN_KIND = 'client'
+
+        def call(worker_class, job, queue, redis_pool)
+          in_tracing_span(
+            operation_name: "sidekiq:#{job['class']}",
+            tags: tags_from_job(job, SPAN_KIND)) do |span|
+            # Inject the details directly into the job
+            tracer.inject(span.context, OpenTracing::FORMAT_TEXT_MAP, job)
+
+            yield
+          end
+        end
+      end
+    end
+  end
+end

lib/gitlab/tracing/sidekiq/server_middleware.rb

@@ -0,0 +1,26 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+
+module Gitlab
+  module Tracing
+    module Sidekiq
+      class ServerMiddleware
+        include SidekiqCommon
+
+        SPAN_KIND = 'server'
+
+        def call(worker, job, queue)
+          context = tracer.extract(OpenTracing::FORMAT_TEXT_MAP, job)
+
+          in_tracing_span(
+            operation_name: "sidekiq:#{job['class']}",
+            child_of: context,
+            tags: tags_from_job(job, SPAN_KIND)) do |span|
+            yield
+          end
+        end
+      end
+    end
+  end
+end

lib/gitlab/tracing/sidekiq/sidekiq_common.rb

@@ -0,0 +1,22 @@
+# frozen_string_literal: true
+
+module Gitlab
+  module Tracing
+    module Sidekiq
+      module SidekiqCommon
+        include Gitlab::Tracing::Common
+
+        def tags_from_job(job, kind)
+          {
+            'component' =>     'sidekiq',
+            'span.kind' =>     kind,
+            'sidekiq.queue' => job['queue'],
+            'sidekiq.jid' =>   job['jid'],
+            'sidekiq.retry' => job['retry'].to_s,
+            'sidekiq.args' =>  job['args']&.join(", ")
+          }
+        end
+      end
+    end
+  end
+end

spec/lib/gitlab/tracing/grpc_interceptor_spec.rb

@@ -0,0 +1,47 @@
+# frozen_string_literal: true
+
+require 'fast_spec_helper'
+
+describe Gitlab::Tracing::GRPCInterceptor do
+  subject { described_class.instance }
+
+  shared_examples_for "a grpc interceptor method" do
+    let(:custom_error) { Class.new(StandardError) }
+
+    it 'yields' do
+      expect { |b| method.call(kwargs, &b) }.to yield_control
+    end
+
+    it 'propagates exceptions' do
+      expect { method.call(kwargs) { raise custom_error } }.to raise_error(custom_error)
+    end
+  end
+
+  describe '#request_response' do
+    let(:method) { subject.method(:request_response) }
+    let(:kwargs) { { request: {}, call: {}, method: 'grc_method', metadata: {} } }
+
+    it_behaves_like 'a grpc interceptor method'
+  end
+
+  describe '#client_streamer' do
+    let(:method) { subject.method(:client_streamer) }
+    let(:kwargs) { { requests: [], call: {}, method: 'grc_method', metadata: {} } }
+
+    it_behaves_like 'a grpc interceptor method'
+  end
+
+  describe '#server_streamer' do
+    let(:method) { subject.method(:server_streamer) }
+    let(:kwargs) { { request: {}, call: {}, method: 'grc_method', metadata: {} } }
+
+    it_behaves_like 'a grpc interceptor method'
+  end
+
+  describe '#bidi_streamer' do
+    let(:method) { subject.method(:bidi_streamer) }
+    let(:kwargs) { { requests: [], call: {}, method: 'grc_method', metadata: {} } }
+
+    it_behaves_like 'a grpc interceptor method'
+  end
+end

spec/lib/gitlab/tracing/rack_middleware_spec.rb

@@ -0,0 +1,62 @@
+# frozen_string_literal: true
+
+require 'spec_helper'
+
+describe Gitlab::Tracing::RackMiddleware do
+  using RSpec::Parameterized::TableSyntax
+
+  describe '#call' do
+    context 'for normal middleware flow' do
+      let(:fake_app) { -> (env) { fake_app_response } }
+      subject { described_class.new(fake_app) }
+      let(:request) {  }
+
+      context 'for 200 responses' do
+        let(:fake_app_response) { [200, { 'Content-Type': 'text/plain' }, ['OK']] }
+
+        it 'delegates correctly' do
+          expect(subject.call(Rack::MockRequest.env_for("/"))).to eq(fake_app_response)
+        end
+      end
+
+      context 'for 500 responses' do
+        let(:fake_app_response) { [500, { 'Content-Type': 'text/plain' }, ['Error']] }
+
+        it 'delegates correctly' do
+          expect(subject.call(Rack::MockRequest.env_for("/"))).to eq(fake_app_response)
+        end
+      end
+    end
+
+    context 'when an application is raising an exception' do
+      let(:custom_error) { Class.new(StandardError) }
+      let(:fake_app) { ->(env) { raise custom_error } }
+
+      subject { described_class.new(fake_app) }
+
+      it 'delegates propagates exceptions correctly' do
+        expect { subject.call(Rack::MockRequest.env_for("/")) }.to raise_error(custom_error)
+      end
+    end
+  end
+
+  describe '.build_sanitized_url_from_env' do
+    def env_for_url(url)
+      env = Rack::MockRequest.env_for(input_url)
+      env['action_dispatch.parameter_filter'] = [/token/]
+
+      env
+    end
+
+    where(:input_url, :output_url) do
+      '/gitlab-org/gitlab-ce'                              | 'http://example.org/gitlab-org/gitlab-ce'
+      '/gitlab-org/gitlab-ce?safe=1'                       | 'http://example.org/gitlab-org/gitlab-ce?safe=1'
+      '/gitlab-org/gitlab-ce?private_token=secret'         | 'http://example.org/gitlab-org/gitlab-ce?private_token=%5BFILTERED%5D'
+      '/gitlab-org/gitlab-ce?mixed=1&private_token=secret' | 'http://example.org/gitlab-org/gitlab-ce?mixed=1&private_token=%5BFILTERED%5D'
+    end
+
+    with_them do
+      it { expect(described_class.build_sanitized_url_from_env(env_for_url(input_url))).to eq(output_url) }
+    end
+  end
+end

spec/lib/gitlab/tracing/sidekiq/client_middleware_spec.rb

@@ -0,0 +1,43 @@
+# frozen_string_literal: true
+
+require 'fast_spec_helper'
+
+describe Gitlab::Tracing::Sidekiq::ClientMiddleware do
+  describe '#call' do
+    let(:worker_class) { 'test_worker_class' }
+    let(:job) do
+      {
+        'class' => "jobclass",
+        'queue' => "jobqueue",
+        'retry' => 0,
+        'args' =>  %w{1 2 3}
+      }
+    end
+    let(:queue) { 'test_queue' }
+    let(:redis_pool) { double("redis_pool") }
+    let(:custom_error) { Class.new(StandardError) }
+    let(:span) { OpenTracing.start_span('test', ignore_active_scope: true) }
+
+    subject { described_class.new }
+
+    it 'yields' do
+      expect(subject).to receive(:in_tracing_span).with(
+        operation_name: "sidekiq:jobclass",
+        tags: {
+          "component" =>     "sidekiq",
+          "span.kind" =>     "client",
+          "sidekiq.queue" => "jobqueue",
+          "sidekiq.jid" =>   nil,
+          "sidekiq.retry" => "0",
+          "sidekiq.args" =>  "1, 2, 3"
+        }
+      ).and_yield(span)
+
+      expect { |b| subject.call(worker_class, job, queue, redis_pool, &b) }.to yield_control
+    end
+
+    it 'propagates exceptions' do
+      expect { subject.call(worker_class, job, queue, redis_pool) { raise custom_error } }.to raise_error(custom_error)
+    end
+  end
+end

spec/lib/gitlab/tracing/sidekiq/server_middleware_spec.rb

@@ -0,0 +1,43 @@
+# frozen_string_literal: true
+
+require 'fast_spec_helper'
+
+describe Gitlab::Tracing::Sidekiq::ServerMiddleware do
+  describe '#call' do
+    let(:worker_class) { 'test_worker_class' }
+    let(:job) do
+      {
+        'class' => "jobclass",
+        'queue' => "jobqueue",
+        'retry' => 0,
+        'args' =>  %w{1 2 3}
+      }
+    end
+    let(:queue) { 'test_queue' }
+    let(:custom_error) { Class.new(StandardError) }
+    let(:span) { OpenTracing.start_span('test', ignore_active_scope: true) }
+    subject { described_class.new }
+
+    it 'yields' do
+      expect(subject).to receive(:in_tracing_span).with(
+        hash_including(
+          operation_name: "sidekiq:jobclass",
+          tags: {
+            "component" =>     "sidekiq",
+            "span.kind" =>     "server",
+            "sidekiq.queue" => "jobqueue",
+            "sidekiq.jid" =>   nil,
+            "sidekiq.retry" => "0",
+            "sidekiq.args" =>  "1, 2, 3"
+          }
+        )
+      ).and_yield(span)
+
+      expect { |b| subject.call(worker_class, job, queue, &b) }.to yield_control
+    end
+
+    it 'propagates exceptions' do
+      expect { subject.call(worker_class, job, queue) { raise custom_error } }.to raise_error(custom_error)
+    end
+  end
+end