Adds support for Redis and Rails tracingan/dtrace-opentracing-jaeger

Adds Redis and Rails distributed tracing support to the GitLab
application.

17 files changed, 529 insertions, 1 deletions

diff --git a/.rubocop.yml b/.rubocop.yml
index e8e550fdbde..bcff67ded8c 100644
--- a/.rubocop.yml
+++ b/.rubocop.yml
@@ -143,6 +143,7 @@ Naming/FileName:
     - XMPP
     - XSRF
     - XSS
+    - GRPC
 
 # GitLab ###################################################################
 
diff --git a/changelogs/unreleased/an-dtrace-opentracing-jaeger.yml b/changelogs/unreleased/an-dtrace-opentracing-jaeger.yml
new file mode 100644
index 00000000000..829eb38bc3e
--- /dev/null
+++ b/changelogs/unreleased/an-dtrace-opentracing-jaeger.yml
@@ -0,0 +1,5 @@
+---
+title: Add support for distributed tracing to GitLab
+merge_request: 21280
+author:
+type: other
diff --git a/changelogs/unreleased/an-opentracing-propagation.yml b/changelogs/unreleased/an-opentracing-propagation.yml
new file mode 100644
index 00000000000..d9aa7cd0048
--- /dev/null
+++ b/changelogs/unreleased/an-opentracing-propagation.yml
@@ -0,0 +1,5 @@
+---
+title: Adds inter-service OpenTracing propagation
+merge_request: 24239
+author:
+type: other
diff --git a/config/initializers/tracing.rb b/config/initializers/tracing.rb
index be95f30d075..056c580f0a6 100644
--- a/config/initializers/tracing.rb
+++ b/config/initializers/tracing.rb
@@ -3,6 +3,30 @@
 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?
+    config.server_middleware do |chain|
+      chain.add Gitlab::Tracing::Sidekiq::ServerMiddleware
+    end
+  end
+
+  # Instrument Redis calls
+  Gitlab::Tracing::Redis.instrument_client
+
+  # Instrument Rails
+  Gitlab::Tracing::Rails.instrument
+
   # 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
diff --git a/lib/gitlab/gitaly_client.rb b/lib/gitlab/gitaly_client.rb
index 8bf8a3b53cd..85afbd85fe6 100644
--- a/lib/gitlab/gitaly_client.rb
+++ b/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
diff --git a/lib/gitlab/tracing/common.rb b/lib/gitlab/tracing/common.rb
new file mode 100644
index 00000000000..55d6272829d
--- /dev/null
+++ b/lib/gitlab/tracing/common.rb
@@ -0,0 +1,56 @@
+# 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 start_active_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 StandardError => 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)
+
+        if exception.is_a? Exception
+          span.log_kv(
+            'event':        'error',
+            'error.kind':   exception.class.to_s,
+            'error.object': exception,
+            'message':      exception.message,
+            'stack':        exception.backtrace.join("\n")
+          )
+        else
+          span.log_kv(
+            'event':        'error',
+            'error.kind':   exception.class.to_s,
+            'error.object': exception
+          )
+        end
+      end
+    end
+  end
+end
diff --git a/lib/gitlab/tracing/grpc_interceptor.rb b/lib/gitlab/tracing/grpc_interceptor.rb
new file mode 100644
index 00000000000..911294d4841
--- /dev/null
+++ b/lib/gitlab/tracing/grpc_interceptor.rb
@@ -0,0 +1,56 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+require 'grpc'
+
+module Gitlab
+  module Tracing
+    class GRPCInterceptor < GRPC::ClientInterceptor
+      include Common
+      include Singleton
+
+      def initialize
+      end
+
+      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)
+        start_active_span(
+          operation_name: method,
+          tags: {
+            'component':  'grpc',
+            'span.kind':  'client',
+            'grpc.method': method,
+            'grpc.type':   grpc_type
+          }) do |span|
+          OpenTracing.inject(span.context, OpenTracing::FORMAT_TEXT_MAP, metadata)
+          yield
+        end
+      end
+    end
+  end
+end
diff --git a/lib/gitlab/tracing/rack_middleware.rb b/lib/gitlab/tracing/rack_middleware.rb
new file mode 100644
index 00000000000..2d36ac67a1c
--- /dev/null
+++ b/lib/gitlab/tracing/rack_middleware.rb
@@ -0,0 +1,37 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+
+module Gitlab
+  module Tracing
+    class RackMiddleware
+      include Common
+
+      REQUEST_URI = 'REQUEST_URI'
+      REQUEST_METHOD = 'REQUEST_METHOD'
+
+      def initialize(app)
+        @app = app
+      end
+
+      def call(env)
+        method = env[REQUEST_METHOD]
+
+        context = tracer.extract(OpenTracing::FORMAT_RACK, env)
+        start_active_span(
+          operation_name: method,
+          child_of:       context,
+          tags: {
+            'component':   'rack',
+            'span.kind':   'server',
+            'http.method': method,
+            'http.url':    env[REQUEST_URI]
+          }) do |span|
+          @app.call(env).tap do |status_code, _headers, _body|
+            span.set_tag('http.status_code', status_code)
+          end
+        end
+      end
+    end
+  end
+end
diff --git a/lib/gitlab/tracing/rails.rb b/lib/gitlab/tracing/rails.rb
new file mode 100644
index 00000000000..5a109c647bb
--- /dev/null
+++ b/lib/gitlab/tracing/rails.rb
@@ -0,0 +1,59 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+
+module Gitlab
+  module Tracing
+    module Rails
+      def self.instrument
+        ActiveSupport::Notifications.subscribe('sql.active_record') do |_, start, finish, _, payload|
+          operation_name = payload.fetch(:name)
+
+          connection_config = ActiveRecord::Base.connection_config
+
+          trace_rails_instrumentation(operation_name: operation_name || "sql.query",
+                                      start_time: start,
+                                      end_time: finish,
+                                      tags: {
+                                        :'component' => 'ActiveRecord',
+                                        :'span.kind' => 'client',
+                                        :'db.instance' => connection_config.fetch(:database),
+                                        :'db.vendor' => connection_config.fetch(:adapter),
+                                        :'db.connection_id' => payload.fetch(:connection_id, 'unknown'),
+                                        :'db.cached' => payload.fetch(:cached, false),
+                                        :'db.statement' => payload.fetch(:sql),
+                                        :'db.type' => 'sql'
+                                      },
+                                      exception: payload[:exception])
+        end
+
+        ActiveSupport::Notifications.subscribe("render_template.action_view") do |_, start, finish, _, payload|
+          trace_rails_instrumentation(
+            operation_name:      'template.render',
+            start_time:          start,
+            end_time:            finish,
+            tags: {
+              :component =>         'ActionView',
+              :'span.kind' =>       'client',
+              :'template.id' =>     payload.fetch(:identifier),
+              :'template.layout' => payload.fetch(:layout)
+            },
+            exception:           payload[:exception])
+        end
+      end
+
+      private
+
+      def self.trace_rails_instrumentation(operation_name:, start_time:, end_time:, tags:, exception:)
+        span = OpenTracing.start_span(operation_name,
+          start_time: start_time,
+          tags: tags)
+
+        log_exception_on_span(span, exception) if exception
+
+        span.finish(end_time: end_time)
+      end
+    end
+  end
+end
+
diff --git a/lib/gitlab/tracing/redis.rb b/lib/gitlab/tracing/redis.rb
new file mode 100644
index 00000000000..92be44c2d19
--- /dev/null
+++ b/lib/gitlab/tracing/redis.rb
@@ -0,0 +1,70 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+
+module Gitlab
+  module Tracing
+    module Redis
+      include Common
+
+      MAX_SENT_REDIS_COMMAND_LENGTH = 240
+
+      def self.instrument_client
+        ::Redis::Client.class_exec do
+          prepend RedisTracingInstrumented
+        end
+      end
+
+      private
+
+      module RedisTracingInstrumented
+        include Common
+        def call(*args, &block)
+          # For Redis calls, certain systems (Sidekiq in particular) will poll Redis
+          # periodically, outside of a trace scope. In this event, don't trace the
+          # call
+          scope = OpenTracing.scope_manager.active
+          return super(*args, &block) unless scope
+
+          start_active_span(operation_name: "redis.call",
+            tags: {
+              :component =>       'redis',
+              :'span.kind' =>     'client',
+              :'db.host' =>       self.host,
+              :'db.port' =>       self.port,
+              :'redis.db' =>      self.db,
+              :'redis.command' => quantize_redis_arguments(*args),
+              :'redis.args.count' => args.length
+            }) do |span|
+            super(*args, &block)
+          end
+        end
+
+        # Turns an array of redis arguments into a trace-worthy string
+        def quantize_redis_arguments(args)
+          args.inject("") do |memo, arg|
+            str = ""
+            begin
+              str = arg.to_s.encode('UTF-8', 'binary', invalid: :replace, undef: :replace, replace: '')
+            rescue
+              # Don't stumble on encoding errors while generating tracing
+              str = "?"
+            end
+
+            str = str.slice(0, 19) + "…" if str.length > 20
+
+            memo = memo == "" ? str : memo + " " + str
+            if memo.length > MAX_SENT_REDIS_COMMAND_LENGTH
+              memo = memo.slice(0, MAX_SENT_REDIS_COMMAND_LENGTH - 1) + "…"
+              # No need to iterate over the rest of the arguments
+              break memo
+            end
+
+            memo
+          end
+        end
+      end
+    end
+  end
+end
+
diff --git a/lib/gitlab/tracing/sidekiq/client_middleware.rb b/lib/gitlab/tracing/sidekiq/client_middleware.rb
new file mode 100644
index 00000000000..96d9696ed08
--- /dev/null
+++ b/lib/gitlab/tracing/sidekiq/client_middleware.rb
@@ -0,0 +1,23 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+
+module Gitlab
+  module Tracing
+    module Sidekiq
+      class ClientMiddleware
+        include SidekiqCommon
+
+        def call(worker_class, job, queue, redis_pool)
+          start_active_span(
+            operation_name: job['class'],
+            tags: tags_from_job(job, 'client')) 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
diff --git a/lib/gitlab/tracing/sidekiq/server_middleware.rb b/lib/gitlab/tracing/sidekiq/server_middleware.rb
new file mode 100644
index 00000000000..3728ee882c7
--- /dev/null
+++ b/lib/gitlab/tracing/sidekiq/server_middleware.rb
@@ -0,0 +1,24 @@
+# frozen_string_literal: true
+
+require 'opentracing'
+
+module Gitlab
+  module Tracing
+    module Sidekiq
+      class ServerMiddleware
+        include SidekiqCommon
+
+        def call(worker, job, queue)
+          context = tracer.extract(OpenTracing::FORMAT_TEXT_MAP, job)
+
+          start_active_span(
+            operation_name: job['class'],
+            child_of: context,
+            tags: tags_from_job(job, 'server')) do |span|
+            yield
+          end
+        end
+      end
+    end
+  end
+end
diff --git a/lib/gitlab/tracing/sidekiq/sidekiq_common.rb b/lib/gitlab/tracing/sidekiq/sidekiq_common.rb
new file mode 100644
index 00000000000..dec8b6e819e
--- /dev/null
+++ b/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
diff --git a/spec/lib/gitlab/tracing/grpc_interceptor_spec.rb b/spec/lib/gitlab/tracing/grpc_interceptor_spec.rb
new file mode 100644
index 00000000000..7f5aecb7baa
--- /dev/null
+++ b/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
diff --git a/spec/lib/gitlab/tracing/rack_middleware_spec.rb b/spec/lib/gitlab/tracing/rack_middleware_spec.rb
new file mode 100644
index 00000000000..1f104f00522
--- /dev/null
+++ b/spec/lib/gitlab/tracing/rack_middleware_spec.rb
@@ -0,0 +1,47 @@
+# frozen_string_literal: true
+
+require 'fast_spec_helper'
+
+describe Gitlab::Tracing::RackMiddleware do
+  describe '#call' do
+    let(:env_hash) do
+      {
+        "REQUEST_URI": "/api/endpoint",
+        "REQUEST_METHOD": "GET"
+      }
+    end
+
+    context 'when an application is working' do
+      let(:app_response) { [200, { 'Content-Type': 'text/plain' }, ['OK']] }
+      let(:app) { lambda {|env| app_response } }
+
+      subject { described_class.new(app) }
+
+      it 'delegates correctly' do
+        expect(subject.call(env_hash)).to eq(app_response)
+      end
+    end
+
+    context 'when an application is failing' do
+      let(:app_response) { [500, { 'Content-Type': 'text/plain' }, ['Error']] }
+      let(:app) { lambda {|env| app_response } }
+
+      subject { described_class.new(app) }
+
+      it 'delegates correctly' do
+        expect(subject.call(env_hash)).to eq(app_response)
+      end
+    end
+
+    context 'when an application is raising an exception' do
+      let(:custom_error) { Class.new(StandardError) }
+      let(:app) { lambda {|env| raise custom_error } }
+
+      subject { described_class.new(app) }
+
+      it 'delegates propagates exceptions correctly' do
+        expect { subject.call(env_hash) }.to raise_error(custom_error)
+      end
+    end
+  end
+end
diff --git a/spec/lib/gitlab/tracing/sidekiq/client_middleware_spec.rb b/spec/lib/gitlab/tracing/sidekiq/client_middleware_spec.rb
new file mode 100644
index 00000000000..b8267a0165e
--- /dev/null
+++ b/spec/lib/gitlab/tracing/sidekiq/client_middleware_spec.rb
@@ -0,0 +1,23 @@
+# 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) { {} }
+    let(:queue) { 'test_queue' }
+    let(:redis_pool) { {} }
+    let(:custom_error) { Class.new(StandardError) }
+
+    subject { described_class.new() }
+
+    it 'yields' do
+      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
diff --git a/spec/lib/gitlab/tracing/sidekiq/server_middleware_spec.rb b/spec/lib/gitlab/tracing/sidekiq/server_middleware_spec.rb
new file mode 100644
index 00000000000..33a4b3e839d
--- /dev/null
+++ b/spec/lib/gitlab/tracing/sidekiq/server_middleware_spec.rb
@@ -0,0 +1,22 @@
+# 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) { {} }
+    let(:queue) { 'test_queue' }
+    let(:custom_error) { Class.new(StandardError) }
+
+    subject { described_class.new() }
+
+    it 'yields' do
+      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