diff options
author | Grzegorz Bizon <grzegorz@gitlab.com> | 2017-11-06 21:17:24 +0000 |
---|---|---|
committer | Grzegorz Bizon <grzegorz@gitlab.com> | 2017-11-06 21:17:24 +0000 |
commit | 4da03e9977ea3fa5bb422ab0f23f0a60406c7073 (patch) | |
tree | 4e05b131ae65a6083dc77f74a978f95ba51150d7 | |
parent | c3d15fa620f218c03dea7100a9e72e18458e4ef3 (diff) | |
parent | 5a085dc12670e6ececa566fc16172da08bac0972 (diff) | |
download | gitlab-ce-4da03e9977ea3fa5bb422ab0f23f0a60406c7073.tar.gz |
Merge branch 'pawel/metrics-to-prometheus-33643' into 'master'
Add all InfluxDB metrics to prometheus
See merge request gitlab-org/gitlab-ce!13891
40 files changed, 1000 insertions, 553 deletions
diff --git a/changelogs/unreleased/pawel-metrics-to-prometheus-33643.yml b/changelogs/unreleased/pawel-metrics-to-prometheus-33643.yml new file mode 100644 index 00000000000..abab2e55f90 --- /dev/null +++ b/changelogs/unreleased/pawel-metrics-to-prometheus-33643.yml @@ -0,0 +1,5 @@ +--- +title: Add Prometheus equivalent of all InfluxDB metrics +merge_request: 13891 +author: +type: changed diff --git a/config/initializers/1_settings.rb b/config/initializers/1_settings.rb index 12694f8016f..d1156b0c8a8 100644 --- a/config/initializers/1_settings.rb +++ b/config/initializers/1_settings.rb @@ -535,6 +535,7 @@ Settings.webpack.dev_server['port'] ||= 3808 Settings['monitoring'] ||= Settingslogic.new({}) Settings.monitoring['ip_whitelist'] ||= ['127.0.0.1/8'] Settings.monitoring['unicorn_sampler_interval'] ||= 10 +Settings.monitoring['ruby_sampler_interval'] ||= 60 Settings.monitoring['sidekiq_exporter'] ||= Settingslogic.new({}) Settings.monitoring.sidekiq_exporter['enabled'] ||= false Settings.monitoring.sidekiq_exporter['address'] ||= 'localhost' diff --git a/config/initializers/7_prometheus_metrics.rb b/config/initializers/7_prometheus_metrics.rb index 31839297523..e8f33593fe0 100644 --- a/config/initializers/7_prometheus_metrics.rb +++ b/config/initializers/7_prometheus_metrics.rb @@ -11,7 +11,15 @@ Prometheus::Client.configure do |config| config.multiprocess_files_dir ||= Rails.root.join('tmp/prometheus_multiproc_dir') end - config.pid_provider = Prometheus::Client::Support::Unicorn.method(:worker_pid_provider) + config.pid_provider = -> do + wid = Prometheus::Client::Support::Unicorn.worker_id + wid = Process.pid if wid.nil? + if wid.nil? + "process_pid_#{Process.pid}" + else + "worker_id_#{wid}" + end + end end Sidekiq.configure_server do |config| @@ -19,3 +27,11 @@ Sidekiq.configure_server do |config| Gitlab::Metrics::SidekiqMetricsExporter.instance.start end end + +if Gitlab::Metrics.prometheus_metrics_enabled? + unless Sidekiq.server? + Gitlab::Metrics::Samplers::UnicornSampler.initialize_instance(Settings.monitoring.unicorn_sampler_interval).start + end + + Gitlab::Metrics::Samplers::RubySampler.initialize_instance(Settings.monitoring.ruby_sampler_interval).start +end diff --git a/config/initializers/8_metrics.rb b/config/initializers/8_metrics.rb index 9c53a33d245..7ef594836d6 100644 --- a/config/initializers/8_metrics.rb +++ b/config/initializers/8_metrics.rb @@ -118,10 +118,6 @@ def instrument_classes(instrumentation) end # rubocop:enable Metrics/AbcSize -unless Sidekiq.server? - Gitlab::Metrics::UnicornSampler.initialize_instance(Settings.monitoring.unicorn_sampler_interval).start -end - Gitlab::Application.configure do |config| # 0 should be Sentry to catch errors in this middleware config.middleware.insert(1, Gitlab::Metrics::RequestsRackMiddleware) @@ -187,7 +183,7 @@ if Gitlab::Metrics.enabled? GC::Profiler.enable - Gitlab::Metrics::InfluxSampler.initialize_instance.start + Gitlab::Metrics::Samplers::InfluxSampler.initialize_instance.start module TrackNewRedisConnections def connect(*args) diff --git a/lib/gitlab/daemon.rb b/lib/gitlab/daemon.rb index dfd17e35707..f07fd1dfdda 100644 --- a/lib/gitlab/daemon.rb +++ b/lib/gitlab/daemon.rb @@ -43,7 +43,7 @@ module Gitlab if thread thread.wakeup if thread.alive? - thread.join + thread.join unless Thread.current == thread @thread = nil end end diff --git a/lib/gitlab/metrics/background_transaction.rb b/lib/gitlab/metrics/background_transaction.rb new file mode 100644 index 00000000000..d01de5eef0a --- /dev/null +++ b/lib/gitlab/metrics/background_transaction.rb @@ -0,0 +1,16 @@ +module Gitlab + module Metrics + class BackgroundTransaction < Transaction + def initialize(worker_class) + super() + @worker_class = worker_class + end + + protected + + def labels + { controller: @worker_class.name, action: 'perform' } + end + end + end +end diff --git a/lib/gitlab/metrics/base_sampler.rb b/lib/gitlab/metrics/base_sampler.rb deleted file mode 100644 index 716d20bb91a..00000000000 --- a/lib/gitlab/metrics/base_sampler.rb +++ /dev/null @@ -1,63 +0,0 @@ -require 'logger' -module Gitlab - module Metrics - class BaseSampler < Daemon - # interval - The sampling interval in seconds. - def initialize(interval) - interval_half = interval.to_f / 2 - - @interval = interval - @interval_steps = (-interval_half..interval_half).step(0.1).to_a - - super() - end - - def safe_sample - sample - rescue => e - Rails.logger.warn("#{self.class}: #{e}, stopping") - stop - end - - def sample - raise NotImplementedError - end - - # Returns the sleep interval with a random adjustment. - # - # The random adjustment is put in place to ensure we: - # - # 1. Don't generate samples at the exact same interval every time (thus - # potentially missing anything that happens in between samples). - # 2. Don't sample data at the same interval two times in a row. - def sleep_interval - while (step = @interval_steps.sample) - if step != @last_step - @last_step = step - - return @interval + @last_step - end - end - end - - private - - attr_reader :running - - def start_working - @running = true - sleep(sleep_interval) - - while running - safe_sample - - sleep(sleep_interval) - end - end - - def stop_working - @running = false - end - end - end -end diff --git a/lib/gitlab/metrics/influx_db.rb b/lib/gitlab/metrics/influx_db.rb index 7b06bb953aa..bdf7910b7c7 100644 --- a/lib/gitlab/metrics/influx_db.rb +++ b/lib/gitlab/metrics/influx_db.rb @@ -11,6 +11,8 @@ module Gitlab settings[:enabled] || false end + # Prometheus histogram buckets used for arbitrary code measurements + EXECUTION_MEASUREMENT_BUCKETS = [0.001, 0.002, 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1].freeze RAILS_ROOT = Rails.root.to_s METRICS_ROOT = Rails.root.join('lib', 'gitlab', 'metrics').to_s PATH_REGEX = /^#{RAILS_ROOT}\/?/ @@ -99,24 +101,27 @@ module Gitlab cpu_stop = System.cpu_time real_stop = Time.now.to_f - real_time = (real_stop - real_start) * 1000.0 + real_time = (real_stop - real_start) cpu_time = cpu_stop - cpu_start - trans.increment("#{name}_real_time", real_time) - trans.increment("#{name}_cpu_time", cpu_time) - trans.increment("#{name}_call_count", 1) + Gitlab::Metrics.histogram("gitlab_#{name}_real_duration_seconds".to_sym, + "Measure #{name}", + Transaction::BASE_LABELS, + EXECUTION_MEASUREMENT_BUCKETS) + .observe(trans.labels, real_time) - retval - end + Gitlab::Metrics.histogram("gitlab_#{name}_cpu_duration_seconds".to_sym, + "Measure #{name}", + Transaction::BASE_LABELS, + EXECUTION_MEASUREMENT_BUCKETS) + .observe(trans.labels, cpu_time / 1000.0) - # Adds a tag to the current transaction (if any) - # - # name - The name of the tag to add. - # value - The value of the tag. - def tag_transaction(name, value) - trans = current_transaction + # InfluxDB stores the _real_time time values as milliseconds + trans.increment("#{name}_real_time", real_time * 1000, false) + trans.increment("#{name}_cpu_time", cpu_time, false) + trans.increment("#{name}_call_count", 1, false) - trans&.add_tag(name, value) + retval end # Sets the action of the current transaction (if any) diff --git a/lib/gitlab/metrics/influx_sampler.rb b/lib/gitlab/metrics/influx_sampler.rb deleted file mode 100644 index 6db1dd755b7..00000000000 --- a/lib/gitlab/metrics/influx_sampler.rb +++ /dev/null @@ -1,101 +0,0 @@ -module Gitlab - module Metrics - # Class that sends certain metrics to InfluxDB at a specific interval. - # - # This class is used to gather statistics that can't be directly associated - # with a transaction such as system memory usage, garbage collection - # statistics, etc. - class InfluxSampler < BaseSampler - # interval - The sampling interval in seconds. - def initialize(interval = Metrics.settings[:sample_interval]) - super(interval) - @last_step = nil - - @metrics = [] - - @last_minor_gc = Delta.new(GC.stat[:minor_gc_count]) - @last_major_gc = Delta.new(GC.stat[:major_gc_count]) - - if Gitlab::Metrics.mri? - require 'allocations' - - Allocations.start - end - end - - def sample - sample_memory_usage - sample_file_descriptors - sample_objects - sample_gc - - flush - ensure - GC::Profiler.clear - @metrics.clear - end - - def flush - Metrics.submit_metrics(@metrics.map(&:to_hash)) - end - - def sample_memory_usage - add_metric('memory_usage', value: System.memory_usage) - end - - def sample_file_descriptors - add_metric('file_descriptors', value: System.file_descriptor_count) - end - - if Metrics.mri? - def sample_objects - sample = Allocations.to_hash - counts = sample.each_with_object({}) do |(klass, count), hash| - name = klass.name - - next unless name - - hash[name] = count - end - - # Symbols aren't allocated so we'll need to add those manually. - counts['Symbol'] = Symbol.all_symbols.length - - counts.each do |name, count| - add_metric('object_counts', { count: count }, type: name) - end - end - else - def sample_objects - end - end - - def sample_gc - time = GC::Profiler.total_time * 1000.0 - stats = GC.stat.merge(total_time: time) - - # We want the difference of GC runs compared to the last sample, not the - # total amount since the process started. - stats[:minor_gc_count] = - @last_minor_gc.compared_with(stats[:minor_gc_count]) - - stats[:major_gc_count] = - @last_major_gc.compared_with(stats[:major_gc_count]) - - stats[:count] = stats[:minor_gc_count] + stats[:major_gc_count] - - add_metric('gc_statistics', stats) - end - - def add_metric(series, values, tags = {}) - prefix = sidekiq? ? 'sidekiq_' : 'rails_' - - @metrics << Metric.new("#{prefix}#{series}", values, tags) - end - - def sidekiq? - Sidekiq.server? - end - end - end -end diff --git a/lib/gitlab/metrics/instrumentation.rb b/lib/gitlab/metrics/instrumentation.rb index 6aa38542cb4..023e9963493 100644 --- a/lib/gitlab/metrics/instrumentation.rb +++ b/lib/gitlab/metrics/instrumentation.rb @@ -118,19 +118,21 @@ module Gitlab def self.instrument(type, mod, name) return unless Metrics.enabled? - name = name.to_sym + name = name.to_sym target = type == :instance ? mod : mod.singleton_class if type == :instance target = mod - label = "#{mod.name}##{name}" + method_name = "##{name}" method = mod.instance_method(name) else target = mod.singleton_class - label = "#{mod.name}.#{name}" + method_name = ".#{name}" method = mod.method(name) end + label = "#{mod.name}#{method_name}" + unless instrumented?(target) target.instance_variable_set(PROXY_IVAR, Module.new) end @@ -153,7 +155,8 @@ module Gitlab proxy_module.class_eval <<-EOF, __FILE__, __LINE__ + 1 def #{name}(#{args_signature}) if trans = Gitlab::Metrics::Instrumentation.transaction - trans.method_call_for(#{label.to_sym.inspect}).measure { super } + trans.method_call_for(#{label.to_sym.inspect}, #{mod.name.inspect}, "#{method_name}") + .measure { super } else super end diff --git a/lib/gitlab/metrics/method_call.rb b/lib/gitlab/metrics/method_call.rb index d3465e5ec19..90235095306 100644 --- a/lib/gitlab/metrics/method_call.rb +++ b/lib/gitlab/metrics/method_call.rb @@ -2,15 +2,45 @@ module Gitlab module Metrics # Class for tracking timing information about method calls class MethodCall - attr_reader :real_time, :cpu_time, :call_count + MUTEX = Mutex.new + BASE_LABELS = { module: nil, method: nil }.freeze + attr_reader :real_time, :cpu_time, :call_count, :labels + + def self.call_real_duration_histogram + return @call_real_duration_histogram if @call_real_duration_histogram + + MUTEX.synchronize do + @call_real_duration_histogram ||= Gitlab::Metrics.histogram( + :gitlab_method_call_real_duration_seconds, + 'Method calls real duration', + Transaction::BASE_LABELS.merge(BASE_LABELS), + [0.1, 0.2, 0.5, 1, 2, 5, 10] + ) + end + end + + def self.call_cpu_duration_histogram + return @call_cpu_duration_histogram if @call_cpu_duration_histogram + + MUTEX.synchronize do + @call_duration_histogram ||= Gitlab::Metrics.histogram( + :gitlab_method_call_cpu_duration_seconds, + 'Method calls cpu duration', + Transaction::BASE_LABELS.merge(BASE_LABELS), + [0.1, 0.2, 0.5, 1, 2, 5, 10] + ) + end + end # name - The full name of the method (including namespace) such as # `User#sign_in`. # - # series - The series to use for storing the data. - def initialize(name, series) + def initialize(name, module_name, method_name, transaction) + @module_name = module_name + @method_name = method_name + @transaction = transaction @name = name - @series = series + @labels = { module: @module_name, method: @method_name } @real_time = 0 @cpu_time = 0 @call_count = 0 @@ -22,21 +52,27 @@ module Gitlab start_cpu = System.cpu_time retval = yield - @real_time += System.monotonic_time - start_real - @cpu_time += System.cpu_time - start_cpu + real_time = System.monotonic_time - start_real + cpu_time = System.cpu_time - start_cpu + + @real_time += real_time + @cpu_time += cpu_time @call_count += 1 + self.class.call_real_duration_histogram.observe(@transaction.labels.merge(labels), real_time / 1000.0) + self.class.call_cpu_duration_histogram.observe(@transaction.labels.merge(labels), cpu_time / 1000.0) + retval end # Returns a Metric instance of the current method call. def to_metric Metric.new( - @series, + Instrumentation.series, { - duration: real_time, + duration: real_time, cpu_duration: cpu_time, - call_count: call_count + call_count: call_count }, method: @name ) diff --git a/lib/gitlab/metrics/prometheus.rb b/lib/gitlab/metrics/prometheus.rb index 460dab47276..09103b4ca2d 100644 --- a/lib/gitlab/metrics/prometheus.rb +++ b/lib/gitlab/metrics/prometheus.rb @@ -5,6 +5,9 @@ module Gitlab module Prometheus include Gitlab::CurrentSettings + REGISTRY_MUTEX = Mutex.new + PROVIDER_MUTEX = Mutex.new + def metrics_folder_present? multiprocess_files_dir = ::Prometheus::Client.configuration.multiprocess_files_dir @@ -20,23 +23,38 @@ module Gitlab end def registry - @registry ||= ::Prometheus::Client.registry + return @registry if @registry + + REGISTRY_MUTEX.synchronize do + @registry ||= ::Prometheus::Client.registry + end end def counter(name, docstring, base_labels = {}) - provide_metric(name) || registry.counter(name, docstring, base_labels) + safe_provide_metric(:counter, name, docstring, base_labels) end def summary(name, docstring, base_labels = {}) - provide_metric(name) || registry.summary(name, docstring, base_labels) + safe_provide_metric(:summary, name, docstring, base_labels) end def gauge(name, docstring, base_labels = {}, multiprocess_mode = :all) - provide_metric(name) || registry.gauge(name, docstring, base_labels, multiprocess_mode) + safe_provide_metric(:gauge, name, docstring, base_labels, multiprocess_mode) end def histogram(name, docstring, base_labels = {}, buckets = ::Prometheus::Client::Histogram::DEFAULT_BUCKETS) - provide_metric(name) || registry.histogram(name, docstring, base_labels, buckets) + safe_provide_metric(:histogram, name, docstring, base_labels, buckets) + end + + private + + def safe_provide_metric(method, name, *args) + metric = provide_metric(name) + return metric if metric + + PROVIDER_MUTEX.synchronize do + provide_metric(name) || registry.method(method).call(name, *args) + end end def provide_metric(name) @@ -47,8 +65,6 @@ module Gitlab end end - private - def prometheus_metrics_enabled_unmemoized metrics_folder_present? && current_application_settings[:prometheus_metrics_enabled] || false end diff --git a/lib/gitlab/metrics/rack_middleware.rb b/lib/gitlab/metrics/rack_middleware.rb index adc0db1a874..2d45765df3f 100644 --- a/lib/gitlab/metrics/rack_middleware.rb +++ b/lib/gitlab/metrics/rack_middleware.rb @@ -2,20 +2,6 @@ module Gitlab module Metrics # Rack middleware for tracking Rails and Grape requests. class RackMiddleware - CONTROLLER_KEY = 'action_controller.instance'.freeze - ENDPOINT_KEY = 'api.endpoint'.freeze - CONTENT_TYPES = { - 'text/html' => :html, - 'text/plain' => :txt, - 'application/json' => :json, - 'text/js' => :js, - 'application/atom+xml' => :atom, - 'image/png' => :png, - 'image/jpeg' => :jpeg, - 'image/gif' => :gif, - 'image/svg+xml' => :svg - }.freeze - def initialize(app) @app = app end @@ -35,12 +21,6 @@ module Gitlab # Even in the event of an error we want to submit any metrics we # might've gathered up to this point. ensure - if env[CONTROLLER_KEY] - tag_controller(trans, env) - elsif env[ENDPOINT_KEY] - tag_endpoint(trans, env) - end - trans.finish end @@ -48,60 +28,19 @@ module Gitlab end def transaction_from_env(env) - trans = Transaction.new + trans = WebTransaction.new(env) - trans.set(:request_uri, filtered_path(env)) - trans.set(:request_method, env['REQUEST_METHOD']) + trans.set(:request_uri, filtered_path(env), false) + trans.set(:request_method, env['REQUEST_METHOD'], false) trans end - def tag_controller(trans, env) - controller = env[CONTROLLER_KEY] - action = "#{controller.class.name}##{controller.action_name}" - suffix = CONTENT_TYPES[controller.content_type] - - if suffix && suffix != :html - action += ".#{suffix}" - end - - trans.action = action - end - - def tag_endpoint(trans, env) - endpoint = env[ENDPOINT_KEY] - - begin - route = endpoint.route - rescue - # endpoint.route is calling env[Grape::Env::GRAPE_ROUTING_ARGS][:route_info] - # but env[Grape::Env::GRAPE_ROUTING_ARGS] is nil in the case of a 405 response - # so we're rescuing exceptions and bailing out - end - - if route - path = endpoint_paths_cache[route.request_method][route.path] - trans.action = "Grape##{route.request_method} #{path}" - end - end - private def filtered_path(env) ActionDispatch::Request.new(env).filtered_path.presence || env['REQUEST_URI'] end - - def endpoint_paths_cache - @endpoint_paths_cache ||= Hash.new do |hash, http_method| - hash[http_method] = Hash.new do |inner_hash, raw_path| - inner_hash[raw_path] = endpoint_instrumentable_path(raw_path) - end - end - end - - def endpoint_instrumentable_path(raw_path) - raw_path.sub('(.:format)', '').sub('/:version', '') - end end end end diff --git a/lib/gitlab/metrics/samplers/base_sampler.rb b/lib/gitlab/metrics/samplers/base_sampler.rb new file mode 100644 index 00000000000..37f90c4673d --- /dev/null +++ b/lib/gitlab/metrics/samplers/base_sampler.rb @@ -0,0 +1,64 @@ +require 'logger' + +module Gitlab + module Metrics + module Samplers + class BaseSampler < Daemon + # interval - The sampling interval in seconds. + def initialize(interval) + interval_half = interval.to_f / 2 + + @interval = interval + @interval_steps = (-interval_half..interval_half).step(0.1).to_a + + super() + end + + def safe_sample + sample + rescue => e + Rails.logger.warn("#{self.class}: #{e}, stopping") + stop + end + + def sample + raise NotImplementedError + end + + # Returns the sleep interval with a random adjustment. + # + # The random adjustment is put in place to ensure we: + # + # 1. Don't generate samples at the exact same interval every time (thus + # potentially missing anything that happens in between samples). + # 2. Don't sample data at the same interval two times in a row. + def sleep_interval + while step = @interval_steps.sample + if step != @last_step + @last_step = step + + return @interval + @last_step + end + end + end + + private + + attr_reader :running + + def start_working + @running = true + sleep(sleep_interval) + while running + safe_sample + sleep(sleep_interval) + end + end + + def stop_working + @running = false + end + end + end + end +end diff --git a/lib/gitlab/metrics/samplers/influx_sampler.rb b/lib/gitlab/metrics/samplers/influx_sampler.rb new file mode 100644 index 00000000000..f4f9b5ca792 --- /dev/null +++ b/lib/gitlab/metrics/samplers/influx_sampler.rb @@ -0,0 +1,103 @@ +module Gitlab + module Metrics + module Samplers + # Class that sends certain metrics to InfluxDB at a specific interval. + # + # This class is used to gather statistics that can't be directly associated + # with a transaction such as system memory usage, garbage collection + # statistics, etc. + class InfluxSampler < BaseSampler + # interval - The sampling interval in seconds. + def initialize(interval = Metrics.settings[:sample_interval]) + super(interval) + @last_step = nil + + @metrics = [] + + @last_minor_gc = Delta.new(GC.stat[:minor_gc_count]) + @last_major_gc = Delta.new(GC.stat[:major_gc_count]) + + if Gitlab::Metrics.mri? + require 'allocations' + + Allocations.start + end + end + + def sample + sample_memory_usage + sample_file_descriptors + sample_objects + sample_gc + + flush + ensure + GC::Profiler.clear + @metrics.clear + end + + def flush + Metrics.submit_metrics(@metrics.map(&:to_hash)) + end + + def sample_memory_usage + add_metric('memory_usage', value: System.memory_usage) + end + + def sample_file_descriptors + add_metric('file_descriptors', value: System.file_descriptor_count) + end + + if Metrics.mri? + def sample_objects + sample = Allocations.to_hash + counts = sample.each_with_object({}) do |(klass, count), hash| + name = klass.name + + next unless name + + hash[name] = count + end + + # Symbols aren't allocated so we'll need to add those manually. + counts['Symbol'] = Symbol.all_symbols.length + + counts.each do |name, count| + add_metric('object_counts', { count: count }, type: name) + end + end + else + def sample_objects + end + end + + def sample_gc + time = GC::Profiler.total_time * 1000.0 + stats = GC.stat.merge(total_time: time) + + # We want the difference of GC runs compared to the last sample, not the + # total amount since the process started. + stats[:minor_gc_count] = + @last_minor_gc.compared_with(stats[:minor_gc_count]) + + stats[:major_gc_count] = + @last_major_gc.compared_with(stats[:major_gc_count]) + + stats[:count] = stats[:minor_gc_count] + stats[:major_gc_count] + + add_metric('gc_statistics', stats) + end + + def add_metric(series, values, tags = {}) + prefix = sidekiq? ? 'sidekiq_' : 'rails_' + + @metrics << Metric.new("#{prefix}#{series}", values, tags) + end + + def sidekiq? + Sidekiq.server? + end + end + end + end +end diff --git a/lib/gitlab/metrics/samplers/ruby_sampler.rb b/lib/gitlab/metrics/samplers/ruby_sampler.rb new file mode 100644 index 00000000000..8b5a60e6b8b --- /dev/null +++ b/lib/gitlab/metrics/samplers/ruby_sampler.rb @@ -0,0 +1,110 @@ +require 'prometheus/client/support/unicorn' + +module Gitlab + module Metrics + module Samplers + class RubySampler < BaseSampler + def metrics + @metrics ||= init_metrics + end + + def with_prefix(prefix, name) + "ruby_#{prefix}_#{name}".to_sym + end + + def to_doc_string(name) + name.to_s.humanize + end + + def labels + {} + end + + def initialize(interval) + super(interval) + + if Metrics.mri? + require 'allocations' + + Allocations.start + end + end + + def init_metrics + metrics = {} + metrics[:sampler_duration] = Metrics.histogram(with_prefix(:sampler_duration, :seconds), 'Sampler time', {}) + metrics[:total_time] = Metrics.gauge(with_prefix(:gc, :time_total), 'Total GC time', labels, :livesum) + GC.stat.keys.each do |key| + metrics[key] = Metrics.gauge(with_prefix(:gc, key), to_doc_string(key), labels, :livesum) + end + + metrics[:objects_total] = Metrics.gauge(with_prefix(:objects, :total), 'Objects total', labels.merge(class: nil), :livesum) + metrics[:memory_usage] = Metrics.gauge(with_prefix(:memory, :usage_total), 'Memory used total', labels, :livesum) + metrics[:file_descriptors] = Metrics.gauge(with_prefix(:file, :descriptors_total), 'File descriptors total', labels, :livesum) + + metrics + end + + def sample + start_time = System.monotonic_time + sample_gc + sample_objects + + metrics[:memory_usage].set(labels, System.memory_usage) + metrics[:file_descriptors].set(labels, System.file_descriptor_count) + + metrics[:sampler_duration].observe(labels.merge(worker_label), (System.monotonic_time - start_time) / 1000.0) + ensure + GC::Profiler.clear + end + + private + + def sample_gc + metrics[:total_time].set(labels, GC::Profiler.total_time * 1000) + + GC.stat.each do |key, value| + metrics[key].set(labels, value) + end + end + + def sample_objects + list_objects.each do |name, count| + metrics[:objects_total].set(labels.merge(class: name), count) + end + end + + if Metrics.mri? + def list_objects + sample = Allocations.to_hash + counts = sample.each_with_object({}) do |(klass, count), hash| + name = klass.name + + next unless name + + hash[name] = count + end + + # Symbols aren't allocated so we'll need to add those manually. + counts['Symbol'] = Symbol.all_symbols.length + counts + end + else + def list_objects + end + end + + def worker_label + return {} unless defined?(Unicorn::Worker) + worker_no = ::Prometheus::Client::Support::Unicorn.worker_id + + if worker_no + { unicorn: worker_no } + else + { unicorn: 'master' } + end + end + end + end + end +end diff --git a/lib/gitlab/metrics/samplers/unicorn_sampler.rb b/lib/gitlab/metrics/samplers/unicorn_sampler.rb new file mode 100644 index 00000000000..ea325651fbb --- /dev/null +++ b/lib/gitlab/metrics/samplers/unicorn_sampler.rb @@ -0,0 +1,50 @@ +module Gitlab + module Metrics + module Samplers + class UnicornSampler < BaseSampler + def initialize(interval) + super(interval) + end + + def unicorn_active_connections + @unicorn_active_connections ||= Gitlab::Metrics.gauge(:unicorn_active_connections, 'Unicorn active connections', {}, :max) + end + + def unicorn_queued_connections + @unicorn_queued_connections ||= Gitlab::Metrics.gauge(:unicorn_queued_connections, 'Unicorn queued connections', {}, :max) + end + + def enabled? + # Raindrops::Linux.tcp_listener_stats is only present on Linux + unicorn_with_listeners? && Raindrops::Linux.respond_to?(:tcp_listener_stats) + end + + def sample + Raindrops::Linux.tcp_listener_stats(tcp_listeners).each do |addr, stats| + unicorn_active_connections.set({ type: 'tcp', address: addr }, stats.active) + unicorn_queued_connections.set({ type: 'tcp', address: addr }, stats.queued) + end + + Raindrops::Linux.unix_listener_stats(unix_listeners).each do |addr, stats| + unicorn_active_connections.set({ type: 'unix', address: addr }, stats.active) + unicorn_queued_connections.set({ type: 'unix', address: addr }, stats.queued) + end + end + + private + + def tcp_listeners + @tcp_listeners ||= Unicorn.listener_names.grep(%r{\A[^/]+:\d+\z}) + end + + def unix_listeners + @unix_listeners ||= Unicorn.listener_names - tcp_listeners + end + + def unicorn_with_listeners? + defined?(Unicorn) && Unicorn.listener_names.any? + end + end + end + end +end diff --git a/lib/gitlab/metrics/sidekiq_middleware.rb b/lib/gitlab/metrics/sidekiq_middleware.rb index b983a40611f..55c707d5386 100644 --- a/lib/gitlab/metrics/sidekiq_middleware.rb +++ b/lib/gitlab/metrics/sidekiq_middleware.rb @@ -5,7 +5,7 @@ module Gitlab # This middleware is intended to be used as a server-side middleware. class SidekiqMiddleware def call(worker, message, queue) - trans = Transaction.new("#{worker.class.name}#perform") + trans = BackgroundTransaction.new(worker.class) begin # Old gitlad-shell messages don't provide enqueued_at/created_at attributes diff --git a/lib/gitlab/metrics/subscribers/action_view.rb b/lib/gitlab/metrics/subscribers/action_view.rb index d435a33e9c7..3da474fc1ec 100644 --- a/lib/gitlab/metrics/subscribers/action_view.rb +++ b/lib/gitlab/metrics/subscribers/action_view.rb @@ -15,10 +15,24 @@ module Gitlab private + def metric_view_rendering_duration_seconds + @metric_view_rendering_duration_seconds ||= Gitlab::Metrics.histogram( + :gitlab_view_rendering_duration_seconds, + 'View rendering time', + Transaction::BASE_LABELS.merge({ path: nil }), + [0.001, 0.002, 0.005, 0.01, 0.02, 0.05, 0.1, 0.500, 2.0, 10.0] + ) + end + def track(event) values = values_for(event) tags = tags_for(event) + metric_view_rendering_duration_seconds.observe( + current_transaction.labels.merge(tags), + event.duration + ) + current_transaction.increment(:view_duration, event.duration) current_transaction.add_metric(SERIES, values, tags) end diff --git a/lib/gitlab/metrics/subscribers/active_record.rb b/lib/gitlab/metrics/subscribers/active_record.rb index 96cad941d5c..064299f40c8 100644 --- a/lib/gitlab/metrics/subscribers/active_record.rb +++ b/lib/gitlab/metrics/subscribers/active_record.rb @@ -7,9 +7,10 @@ module Gitlab def sql(event) return unless current_transaction + metric_sql_duration_seconds.observe(current_transaction.labels, event.duration / 1000.0) - current_transaction.increment(:sql_duration, event.duration) - current_transaction.increment(:sql_count, 1) + current_transaction.increment(:sql_duration, event.duration, false) + current_transaction.increment(:sql_count, 1, false) end private @@ -17,6 +18,15 @@ module Gitlab def current_transaction Transaction.current end + + def metric_sql_duration_seconds + @metric_sql_duration_seconds ||= Gitlab::Metrics.histogram( + :gitlab_sql_duration_seconds, + 'SQL time', + Transaction::BASE_LABELS, + [0.001, 0.002, 0.005, 0.01, 0.02, 0.05, 0.1, 0.500, 2.0, 10.0] + ) + end end end end diff --git a/lib/gitlab/metrics/subscribers/rails_cache.rb b/lib/gitlab/metrics/subscribers/rails_cache.rb index aaed2184f44..efd3c9daf79 100644 --- a/lib/gitlab/metrics/subscribers/rails_cache.rb +++ b/lib/gitlab/metrics/subscribers/rails_cache.rb @@ -7,28 +7,29 @@ module Gitlab attach_to :active_support def cache_read(event) - increment(:cache_read, event.duration) + observe(:read, event.duration) return unless current_transaction return if event.payload[:super_operation] == :fetch if event.payload[:hit] - current_transaction.increment(:cache_read_hit_count, 1) + current_transaction.increment(:cache_read_hit_count, 1, false) else - current_transaction.increment(:cache_read_miss_count, 1) + metric_cache_misses_total.increment(current_transaction.labels) + current_transaction.increment(:cache_read_miss_count, 1, false) end end def cache_write(event) - increment(:cache_write, event.duration) + observe(:write, event.duration) end def cache_delete(event) - increment(:cache_delete, event.duration) + observe(:delete, event.duration) end def cache_exist?(event) - increment(:cache_exists, event.duration) + observe(:exists, event.duration) end def cache_fetch_hit(event) @@ -40,16 +41,18 @@ module Gitlab def cache_generate(event) return unless current_transaction + metric_cache_misses_total.increment(current_transaction.labels) current_transaction.increment(:cache_read_miss_count, 1) end - def increment(key, duration) + def observe(key, duration) return unless current_transaction - current_transaction.increment(:cache_duration, duration) - current_transaction.increment(:cache_count, 1) - current_transaction.increment("#{key}_duration".to_sym, duration) - current_transaction.increment("#{key}_count".to_sym, 1) + metric_cache_operation_duration_seconds.observe(current_transaction.labels.merge({ operation: key }), duration / 1000.0) + current_transaction.increment(:cache_duration, duration, false) + current_transaction.increment(:cache_count, 1, false) + current_transaction.increment("cache_#{key}_duration".to_sym, duration, false) + current_transaction.increment("cache_#{key}_count".to_sym, 1, false) end private @@ -57,6 +60,23 @@ module Gitlab def current_transaction Transaction.current end + + def metric_cache_operation_duration_seconds + @metric_cache_operation_duration_seconds ||= Gitlab::Metrics.histogram( + :gitlab_cache_operation_duration_seconds, + 'Cache access time', + Transaction::BASE_LABELS.merge({ action: nil }), + [0.001, 0.002, 0.005, 0.01, 0.02, 0.05, 0.1, 0.500, 2.0, 10.0] + ) + end + + def metric_cache_misses_total + @metric_cache_misses_total ||= Gitlab::Metrics.counter( + :gitlab_cache_misses_total, + 'Cache read miss', + Transaction::BASE_LABELS + ) + end end end end diff --git a/lib/gitlab/metrics/transaction.rb b/lib/gitlab/metrics/transaction.rb index 4f9fb1c7853..ee3afc5ffdb 100644 --- a/lib/gitlab/metrics/transaction.rb +++ b/lib/gitlab/metrics/transaction.rb @@ -2,34 +2,33 @@ module Gitlab module Metrics # Class for storing metrics information of a single transaction. class Transaction + # base labels shared among all transactions + BASE_LABELS = { controller: nil, action: nil }.freeze + THREAD_KEY = :_gitlab_metrics_transaction + METRICS_MUTEX = Mutex.new # The series to store events (e.g. Git pushes) in. EVENT_SERIES = 'events'.freeze attr_reader :tags, :values, :method, :metrics - attr_accessor :action - def self.current Thread.current[THREAD_KEY] end - # action - A String describing the action performed, usually the class - # plus method name. - def initialize(action = nil) + def initialize @metrics = [] @methods = {} - @started_at = nil + @started_at = nil @finished_at = nil @values = Hash.new(0) - @tags = {} - @action = action + @tags = {} @memory_before = 0 - @memory_after = 0 + @memory_after = 0 end def duration @@ -44,12 +43,15 @@ module Gitlab Thread.current[THREAD_KEY] = self @memory_before = System.memory_usage - @started_at = System.monotonic_time + @started_at = System.monotonic_time yield ensure @memory_after = System.memory_usage - @finished_at = System.monotonic_time + @finished_at = System.monotonic_time + + self.class.metric_transaction_duration_seconds.observe(labels, duration * 1000) + self.class.metric_transaction_allocated_memory_bytes.observe(labels, allocated_memory * 1024.0) Thread.current[THREAD_KEY] = nil end @@ -66,33 +68,29 @@ module Gitlab # event_name - The name of the event (e.g. "git_push"). # tags - A set of tags to attach to the event. def add_event(event_name, tags = {}) - @metrics << Metric.new(EVENT_SERIES, - { count: 1 }, - { event: event_name }.merge(tags), - :event) + self.class.metric_event_counter(event_name, tags).increment(tags.merge(labels)) + @metrics << Metric.new(EVENT_SERIES, { count: 1 }, tags.merge(event: event_name), :event) end # Returns a MethodCall object for the given name. - def method_call_for(name) + def method_call_for(name, module_name, method_name) unless method = @methods[name] - @methods[name] = method = MethodCall.new(name, Instrumentation.series) + @methods[name] = method = MethodCall.new(name, module_name, method_name, self) end method end - def increment(name, value) + def increment(name, value, use_prometheus = true) + self.class.metric_transaction_counter(name).increment(labels, value) if use_prometheus @values[name] += value end - def set(name, value) + def set(name, value, use_prometheus = true) + self.class.metric_transaction_gauge(name).set(labels, value) if use_prometheus @values[name] = value end - def add_tag(key, value) - @tags[key] = value - end - def finish track_self submit @@ -117,14 +115,83 @@ module Gitlab submit_hashes = submit.map do |metric| hash = metric.to_hash - - hash[:tags][:action] ||= @action if @action && !metric.event? + hash[:tags][:action] ||= action if action && !metric.event? hash end Metrics.submit_metrics(submit_hashes) end + + def labels + BASE_LABELS + end + + # returns string describing the action performed, usually the class plus method name. + def action + "#{labels[:controller]}##{labels[:action]}" if labels && !labels.empty? + end + + def self.metric_transaction_duration_seconds + return @metric_transaction_duration_seconds if @metric_transaction_duration_seconds + + METRICS_MUTEX.synchronize do + @metric_transaction_duration_seconds ||= Gitlab::Metrics.histogram( + :gitlab_transaction_duration_seconds, + 'Transaction duration', + BASE_LABELS, + [0.001, 0.002, 0.005, 0.01, 0.02, 0.05, 0.1, 0.500, 2.0, 10.0] + ) + end + end + + def self.metric_transaction_allocated_memory_bytes + return @metric_transaction_allocated_memory_bytes if @metric_transaction_allocated_memory_bytes + + METRICS_MUTEX.synchronize do + @metric_transaction_allocated_memory_bytes ||= Gitlab::Metrics.histogram( + :gitlab_transaction_allocated_memory_bytes, + 'Transaction allocated memory bytes', + BASE_LABELS, + [1000, 10000, 20000, 500000, 1000000, 2000000, 5000000, 10000000, 20000000, 100000000] + ) + end + end + + def self.metric_event_counter(event_name, tags) + return @metric_event_counters[event_name] if @metric_event_counters&.has_key?(event_name) + + METRICS_MUTEX.synchronize do + @metric_event_counters ||= {} + @metric_event_counters[event_name] ||= Gitlab::Metrics.counter( + "gitlab_transaction_event_#{event_name}_total".to_sym, + "Transaction event #{event_name} counter", + tags.merge(BASE_LABELS) + ) + end + end + + def self.metric_transaction_counter(name) + return @metric_transaction_counters[name] if @metric_transaction_counters&.has_key?(name) + + METRICS_MUTEX.synchronize do + @metric_transaction_counters ||= {} + @metric_transaction_counters[name] ||= Gitlab::Metrics.counter( + "gitlab_transaction_#{name}_total".to_sym, "Transaction #{name} counter", BASE_LABELS + ) + end + end + + def self.metric_transaction_gauge(name) + return @metric_transaction_gauges[name] if @metric_transaction_gauges&.has_key?(name) + + METRICS_MUTEX.synchronize do + @metric_transaction_gauges ||= {} + @metric_transaction_gauges[name] ||= Gitlab::Metrics.gauge( + "gitlab_transaction_#{name}".to_sym, "Transaction gauge #{name}", BASE_LABELS, :livesum + ) + end + end end end end diff --git a/lib/gitlab/metrics/unicorn_sampler.rb b/lib/gitlab/metrics/unicorn_sampler.rb deleted file mode 100644 index f6987252039..00000000000 --- a/lib/gitlab/metrics/unicorn_sampler.rb +++ /dev/null @@ -1,48 +0,0 @@ -module Gitlab - module Metrics - class UnicornSampler < BaseSampler - def initialize(interval) - super(interval) - end - - def unicorn_active_connections - @unicorn_active_connections ||= Gitlab::Metrics.gauge(:unicorn_active_connections, 'Unicorn active connections', {}, :max) - end - - def unicorn_queued_connections - @unicorn_queued_connections ||= Gitlab::Metrics.gauge(:unicorn_queued_connections, 'Unicorn queued connections', {}, :max) - end - - def enabled? - # Raindrops::Linux.tcp_listener_stats is only present on Linux - unicorn_with_listeners? && Raindrops::Linux.respond_to?(:tcp_listener_stats) - end - - def sample - Raindrops::Linux.tcp_listener_stats(tcp_listeners).each do |addr, stats| - unicorn_active_connections.set({ type: 'tcp', address: addr }, stats.active) - unicorn_queued_connections.set({ type: 'tcp', address: addr }, stats.queued) - end - - Raindrops::Linux.unix_listener_stats(unix_listeners).each do |addr, stats| - unicorn_active_connections.set({ type: 'unix', address: addr }, stats.active) - unicorn_queued_connections.set({ type: 'unix', address: addr }, stats.queued) - end - end - - private - - def tcp_listeners - @tcp_listeners ||= Unicorn.listener_names.grep(%r{\A[^/]+:\d+\z}) - end - - def unix_listeners - @unix_listeners ||= Unicorn.listener_names - tcp_listeners - end - - def unicorn_with_listeners? - defined?(Unicorn) && Unicorn.listener_names.any? - end - end - end -end diff --git a/lib/gitlab/metrics/web_transaction.rb b/lib/gitlab/metrics/web_transaction.rb new file mode 100644 index 00000000000..89ff02a96d6 --- /dev/null +++ b/lib/gitlab/metrics/web_transaction.rb @@ -0,0 +1,82 @@ +module Gitlab + module Metrics + class WebTransaction < Transaction + CONTROLLER_KEY = 'action_controller.instance'.freeze + ENDPOINT_KEY = 'api.endpoint'.freeze + + CONTENT_TYPES = { + 'text/html' => :html, + 'text/plain' => :txt, + 'application/json' => :json, + 'text/js' => :js, + 'application/atom+xml' => :atom, + 'image/png' => :png, + 'image/jpeg' => :jpeg, + 'image/gif' => :gif, + 'image/svg+xml' => :svg + }.freeze + + def initialize(env) + super() + @env = env + end + + def labels + return @labels if @labels + + # memoize transaction labels only source env variables were present + @labels = if @env[CONTROLLER_KEY] + labels_from_controller || {} + elsif @env[ENDPOINT_KEY] + labels_from_endpoint || {} + end + + @labels || {} + end + + private + + def labels_from_controller + controller = @env[CONTROLLER_KEY] + + action = "#{controller.action_name}" + suffix = CONTENT_TYPES[controller.content_type] + + if suffix && suffix != :html + action += ".#{suffix}" + end + + { controller: controller.class.name, action: action } + end + + def labels_from_endpoint + endpoint = @env[ENDPOINT_KEY] + + begin + route = endpoint.route + rescue + # endpoint.route is calling env[Grape::Env::GRAPE_ROUTING_ARGS][:route_info] + # but env[Grape::Env::GRAPE_ROUTING_ARGS] is nil in the case of a 405 response + # so we're rescuing exceptions and bailing out + end + + if route + path = endpoint_paths_cache[route.request_method][route.path] + { controller: 'Grape', action: "#{route.request_method} #{path}" } + end + end + + def endpoint_paths_cache + @endpoint_paths_cache ||= Hash.new do |hash, http_method| + hash[http_method] = Hash.new do |inner_hash, raw_path| + inner_hash[raw_path] = endpoint_instrumentable_path(raw_path) + end + end + end + + def endpoint_instrumentable_path(raw_path) + raw_path.sub('(.:format)', '').sub('/:version', '') + end + end + end +end diff --git a/lib/gitlab/middleware/rails_queue_duration.rb b/lib/gitlab/middleware/rails_queue_duration.rb index 63c3372da51..bc70b2459ef 100644 --- a/lib/gitlab/middleware/rails_queue_duration.rb +++ b/lib/gitlab/middleware/rails_queue_duration.rb @@ -14,11 +14,22 @@ module Gitlab proxy_start = env['HTTP_GITLAB_WORKHORSE_PROXY_START'].presence if trans && proxy_start # Time in milliseconds since gitlab-workhorse started the request - trans.set(:rails_queue_duration, Time.now.to_f * 1_000 - proxy_start.to_f / 1_000_000) + duration = Time.now.to_f * 1_000 - proxy_start.to_f / 1_000_000 + trans.set(:rails_queue_duration, duration) + metric_rails_queue_duration_seconds.observe(trans.labels, duration / 1_000) end @app.call(env) end + + private + + def metric_rails_queue_duration_seconds + @metric_rails_queue_duration_seconds ||= Gitlab::Metrics.histogram( + :gitlab_rails_queue_duration_seconds, + Gitlab::Metrics::Transaction::BASE_LABELS + ) + end end end end diff --git a/spec/initializers/8_metrics_spec.rb b/spec/initializers/8_metrics_spec.rb index 4e6052a9f80..80c77057065 100644 --- a/spec/initializers/8_metrics_spec.rb +++ b/spec/initializers/8_metrics_spec.rb @@ -3,7 +3,6 @@ require 'spec_helper' describe 'instrument_classes' do let(:config) { double(:config) } - let(:unicorn_sampler) { double(:unicorn_sampler) } let(:influx_sampler) { double(:influx_sampler) } before do @@ -11,9 +10,7 @@ describe 'instrument_classes' do allow(config).to receive(:instrument_methods) allow(config).to receive(:instrument_instance_method) allow(config).to receive(:instrument_instance_methods) - allow(Gitlab::Metrics::UnicornSampler).to receive(:initialize_instance).and_return(unicorn_sampler) - allow(Gitlab::Metrics::InfluxSampler).to receive(:initialize_instance).and_return(influx_sampler) - allow(unicorn_sampler).to receive(:start) + allow(Gitlab::Metrics::Samplers::InfluxSampler).to receive(:initialize_instance).and_return(influx_sampler) allow(influx_sampler).to receive(:start) allow(Gitlab::Application).to receive(:configure) end diff --git a/spec/lib/gitlab/metrics/background_transaction_spec.rb b/spec/lib/gitlab/metrics/background_transaction_spec.rb new file mode 100644 index 00000000000..96052b8dc2f --- /dev/null +++ b/spec/lib/gitlab/metrics/background_transaction_spec.rb @@ -0,0 +1,13 @@ +require 'spec_helper' + +describe Gitlab::Metrics::BackgroundTransaction do + let(:test_worker_class) { double(:class, name: 'TestWorker') } + + subject { described_class.new(test_worker_class) } + + describe '#action' do + it 'returns transaction action name' do + expect(subject.action).to eq('TestWorker#perform') + end + end +end diff --git a/spec/lib/gitlab/metrics/instrumentation_spec.rb b/spec/lib/gitlab/metrics/instrumentation_spec.rb index 4b19ee19103..977bc250049 100644 --- a/spec/lib/gitlab/metrics/instrumentation_spec.rb +++ b/spec/lib/gitlab/metrics/instrumentation_spec.rb @@ -1,7 +1,8 @@ require 'spec_helper' describe Gitlab::Metrics::Instrumentation do - let(:transaction) { Gitlab::Metrics::Transaction.new } + let(:env) { {} } + let(:transaction) { Gitlab::Metrics::WebTransaction.new(env) } before do @dummy = Class.new do diff --git a/spec/lib/gitlab/metrics/method_call_spec.rb b/spec/lib/gitlab/metrics/method_call_spec.rb index a247f03b2da..f1e9e414e0d 100644 --- a/spec/lib/gitlab/metrics/method_call_spec.rb +++ b/spec/lib/gitlab/metrics/method_call_spec.rb @@ -1,7 +1,8 @@ require 'spec_helper' describe Gitlab::Metrics::MethodCall do - let(:method_call) { described_class.new('Foo#bar', 'foo') } + let(:transaction) { double(:transaction, labels: {}) } + let(:method_call) { described_class.new('Foo#bar', :Foo, '#bar', transaction) } describe '#measure' do it 'measures the performance of the supplied block' do @@ -11,6 +12,18 @@ describe Gitlab::Metrics::MethodCall do expect(method_call.cpu_time).to be_a_kind_of(Numeric) expect(method_call.call_count).to eq(1) end + + it 'observes the performance of the supplied block' do + expect(described_class.call_real_duration_histogram) + .to receive(:observe) + .with({ module: :Foo, method: '#bar' }, be_a_kind_of(Numeric)) + + expect(described_class.call_cpu_duration_histogram) + .to receive(:observe) + .with({ module: :Foo, method: '#bar' }, be_a_kind_of(Numeric)) + + method_call.measure { 'foo' } + end end describe '#to_metric' do @@ -19,7 +32,7 @@ describe Gitlab::Metrics::MethodCall do metric = method_call.to_metric expect(metric).to be_an_instance_of(Gitlab::Metrics::Metric) - expect(metric.series).to eq('foo') + expect(metric.series).to eq('rails_method_calls') expect(metric.values[:duration]).to be_a_kind_of(Numeric) expect(metric.values[:cpu_duration]).to be_a_kind_of(Numeric) diff --git a/spec/lib/gitlab/metrics/rack_middleware_spec.rb b/spec/lib/gitlab/metrics/rack_middleware_spec.rb index ec415f2bd85..b84387204ee 100644 --- a/spec/lib/gitlab/metrics/rack_middleware_spec.rb +++ b/spec/lib/gitlab/metrics/rack_middleware_spec.rb @@ -18,34 +18,6 @@ describe Gitlab::Metrics::RackMiddleware do expect(middleware.call(env)).to eq('yay') end - it 'tags a transaction with the name and action of a controller' do - klass = double(:klass, name: 'TestController', content_type: 'text/html') - controller = double(:controller, class: klass, action_name: 'show') - - env['action_controller.instance'] = controller - - allow(app).to receive(:call).with(env) - - expect(middleware).to receive(:tag_controller) - .with(an_instance_of(Gitlab::Metrics::Transaction), env) - - middleware.call(env) - end - - it 'tags a transaction with the method and path of the route in the grape endpoint' do - route = double(:route, request_method: "GET", path: "/:version/projects/:id/archive(.:format)") - endpoint = double(:endpoint, route: route) - - env['api.endpoint'] = endpoint - - allow(app).to receive(:call).with(env) - - expect(middleware).to receive(:tag_endpoint) - .with(an_instance_of(Gitlab::Metrics::Transaction), env) - - middleware.call(env) - end - it 'tracks any raised exceptions' do expect(app).to receive(:call).with(env).and_raise(RuntimeError) @@ -60,7 +32,7 @@ describe Gitlab::Metrics::RackMiddleware do let(:transaction) { middleware.transaction_from_env(env) } it 'returns a Transaction' do - expect(transaction).to be_an_instance_of(Gitlab::Metrics::Transaction) + expect(transaction).to be_an_instance_of(Gitlab::Metrics::WebTransaction) end it 'stores the request method and URI in the transaction as values' do @@ -84,58 +56,4 @@ describe Gitlab::Metrics::RackMiddleware do end end end - - describe '#tag_controller' do - let(:transaction) { middleware.transaction_from_env(env) } - let(:content_type) { 'text/html' } - - before do - klass = double(:klass, name: 'TestController') - controller = double(:controller, class: klass, action_name: 'show', content_type: content_type) - - env['action_controller.instance'] = controller - end - - it 'tags a transaction with the name and action of a controller' do - middleware.tag_controller(transaction, env) - - expect(transaction.action).to eq('TestController#show') - end - - context 'when the response content type is not :html' do - let(:content_type) { 'application/json' } - - it 'appends the mime type to the transaction action' do - middleware.tag_controller(transaction, env) - - expect(transaction.action).to eq('TestController#show.json') - end - end - end - - describe '#tag_endpoint' do - let(:transaction) { middleware.transaction_from_env(env) } - - it 'tags a transaction with the method and path of the route in the grape endpount' do - route = double(:route, request_method: "GET", path: "/:version/projects/:id/archive(.:format)") - endpoint = double(:endpoint, route: route) - - env['api.endpoint'] = endpoint - - middleware.tag_endpoint(transaction, env) - - expect(transaction.action).to eq('Grape#GET /projects/:id/archive') - end - - it 'does not tag a transaction if route infos are missing' do - endpoint = double(:endpoint) - allow(endpoint).to receive(:route).and_raise - - env['api.endpoint'] = endpoint - - middleware.tag_endpoint(transaction, env) - - expect(transaction.action).to be_nil - end - end end diff --git a/spec/lib/gitlab/metrics/influx_sampler_spec.rb b/spec/lib/gitlab/metrics/samplers/influx_sampler_spec.rb index 999a9536d82..667e4747897 100644 --- a/spec/lib/gitlab/metrics/influx_sampler_spec.rb +++ b/spec/lib/gitlab/metrics/samplers/influx_sampler_spec.rb @@ -1,6 +1,6 @@ require 'spec_helper' -describe Gitlab::Metrics::InfluxSampler do +describe Gitlab::Metrics::Samplers::InfluxSampler do let(:sampler) { described_class.new(5) } after do diff --git a/spec/lib/gitlab/metrics/samplers/ruby_sampler_spec.rb b/spec/lib/gitlab/metrics/samplers/ruby_sampler_spec.rb new file mode 100644 index 00000000000..53699327da1 --- /dev/null +++ b/spec/lib/gitlab/metrics/samplers/ruby_sampler_spec.rb @@ -0,0 +1,90 @@ +require 'spec_helper' + +describe Gitlab::Metrics::Samplers::RubySampler do + let(:sampler) { described_class.new(5) } + + after do + Allocations.stop if Gitlab::Metrics.mri? + end + + describe '#sample' do + it 'samples various statistics' do + expect(Gitlab::Metrics::System).to receive(:memory_usage) + expect(Gitlab::Metrics::System).to receive(:file_descriptor_count) + expect(sampler).to receive(:sample_objects) + expect(sampler).to receive(:sample_gc) + + sampler.sample + end + + it 'adds a metric containing the memory usage' do + expect(Gitlab::Metrics::System).to receive(:memory_usage) + .and_return(9000) + + expect(sampler.metrics[:memory_usage]).to receive(:set) + .with({}, 9000) + .and_call_original + + sampler.sample + end + + it 'adds a metric containing the amount of open file descriptors' do + expect(Gitlab::Metrics::System).to receive(:file_descriptor_count) + .and_return(4) + + expect(sampler.metrics[:file_descriptors]).to receive(:set) + .with({}, 4) + .and_call_original + + sampler.sample + end + + it 'clears any GC profiles' do + expect(GC::Profiler).to receive(:clear) + + sampler.sample + end + end + + describe '#sample_gc' do + it 'adds a metric containing garbage collection time statistics' do + expect(GC::Profiler).to receive(:total_time).and_return(0.24) + + expect(sampler.metrics[:total_time]).to receive(:set) + .with({}, 240) + .and_call_original + + sampler.sample + end + + it 'adds a metric containing garbage collection statistics' do + GC.stat.keys.each do |key| + expect(sampler.metrics[key]).to receive(:set).with({}, anything).and_call_original + end + + sampler.sample + end + end + + if Gitlab::Metrics.mri? + describe '#sample_objects' do + it 'adds a metric containing the amount of allocated objects' do + expect(sampler.metrics[:objects_total]).to receive(:set) + .with(include(class: anything), be > 0) + .at_least(:once) + .and_call_original + + sampler.sample + end + + it 'ignores classes without a name' do + expect(Allocations).to receive(:to_hash).and_return({ Class.new => 4 }) + + expect(sampler.metrics[:objects_total]).not_to receive(:set) + .with(include(class: 'object_counts'), anything) + + sampler.sample + end + end + end +end diff --git a/spec/lib/gitlab/metrics/unicorn_sampler_spec.rb b/spec/lib/gitlab/metrics/samplers/unicorn_sampler_spec.rb index dc0d1f2e940..771b633a2b9 100644 --- a/spec/lib/gitlab/metrics/unicorn_sampler_spec.rb +++ b/spec/lib/gitlab/metrics/samplers/unicorn_sampler_spec.rb @@ -1,6 +1,6 @@ require 'spec_helper' -describe Gitlab::Metrics::UnicornSampler do +describe Gitlab::Metrics::Samplers::UnicornSampler do subject { described_class.new(1.second) } describe '#sample' do diff --git a/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb b/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb index 0803ce42fac..6d69b5305d2 100644 --- a/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb +++ b/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb @@ -5,8 +5,8 @@ describe Gitlab::Metrics::SidekiqMiddleware do let(:message) { { 'args' => ['test'], 'enqueued_at' => Time.new(2016, 6, 23, 6, 59).to_f } } def run(worker, message) - expect(Gitlab::Metrics::Transaction).to receive(:new) - .with('TestWorker#perform') + expect(Gitlab::Metrics::BackgroundTransaction).to receive(:new) + .with(worker.class) .and_call_original expect_any_instance_of(Gitlab::Metrics::Transaction).to receive(:set) @@ -18,21 +18,18 @@ describe Gitlab::Metrics::SidekiqMiddleware do end describe '#call' do - it 'tracks the transaction' do - worker = double(:worker, class: double(:class, name: 'TestWorker')) + let(:test_worker_class) { double(:class, name: 'TestWorker') } + let(:worker) { double(:worker, class: test_worker_class) } + it 'tracks the transaction' do run(worker, message) end it 'tracks the transaction (for messages without `enqueued_at`)' do - worker = double(:worker, class: double(:class, name: 'TestWorker')) - run(worker, {}) end it 'tracks any raised exceptions' do - worker = double(:worker, class: double(:class, name: 'TestWorker')) - expect_any_instance_of(Gitlab::Metrics::Transaction) .to receive(:run).and_raise(RuntimeError) @@ -45,18 +42,5 @@ describe Gitlab::Metrics::SidekiqMiddleware do expect { middleware.call(worker, message, :test) } .to raise_error(RuntimeError) end - - it 'tags the metrics accordingly' do - tags = { one: 1, two: 2 } - worker = double(:worker, class: double(:class, name: 'TestWorker')) - allow(worker).to receive(:metrics_tags).and_return(tags) - - tags.each do |tag, value| - expect_any_instance_of(Gitlab::Metrics::Transaction).to receive(:add_tag) - .with(tag, value) - end - - run(worker, message) - end end end diff --git a/spec/lib/gitlab/metrics/subscribers/action_view_spec.rb b/spec/lib/gitlab/metrics/subscribers/action_view_spec.rb index e7b595405a8..eca75a4fac1 100644 --- a/spec/lib/gitlab/metrics/subscribers/action_view_spec.rb +++ b/spec/lib/gitlab/metrics/subscribers/action_view_spec.rb @@ -1,7 +1,8 @@ require 'spec_helper' describe Gitlab::Metrics::Subscribers::ActionView do - let(:transaction) { Gitlab::Metrics::Transaction.new } + let(:env) { {} } + let(:transaction) { Gitlab::Metrics::WebTransaction.new(env) } let(:subscriber) { described_class.new } @@ -29,5 +30,13 @@ describe Gitlab::Metrics::Subscribers::ActionView do subscriber.render_template(event) end + + it 'observes view rendering time' do + expect(subscriber.send(:metric_view_rendering_duration_seconds)) + .to receive(:observe) + .with({ view: 'app/views/x.html.haml' }, 2.1) + + subscriber.render_template(event) + end end end diff --git a/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb b/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb index ce6587e993f..9b3698fb4a8 100644 --- a/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb +++ b/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb @@ -1,11 +1,12 @@ require 'spec_helper' describe Gitlab::Metrics::Subscribers::ActiveRecord do - let(:transaction) { Gitlab::Metrics::Transaction.new } + let(:env) { {} } + let(:transaction) { Gitlab::Metrics::WebTransaction.new(env) } let(:subscriber) { described_class.new } let(:event) do - double(:event, duration: 0.2, + double(:event, duration: 2, payload: { sql: 'SELECT * FROM users WHERE id = 10' }) end @@ -20,16 +21,24 @@ describe Gitlab::Metrics::Subscribers::ActiveRecord do end describe 'with a current transaction' do + it 'observes sql_duration metric' do + expect(subscriber).to receive(:current_transaction) + .at_least(:once) + .and_return(transaction) + expect(subscriber.send(:metric_sql_duration_seconds)).to receive(:observe).with({}, 0.002) + subscriber.sql(event) + end + it 'increments the :sql_duration value' do expect(subscriber).to receive(:current_transaction) .at_least(:once) .and_return(transaction) expect(transaction).to receive(:increment) - .with(:sql_duration, 0.2) + .with(:sql_duration, 2, false) expect(transaction).to receive(:increment) - .with(:sql_count, 1) + .with(:sql_count, 1, false) subscriber.sql(event) end diff --git a/spec/lib/gitlab/metrics/subscribers/rails_cache_spec.rb b/spec/lib/gitlab/metrics/subscribers/rails_cache_spec.rb index f04dc8dcc02..58e28592cf9 100644 --- a/spec/lib/gitlab/metrics/subscribers/rails_cache_spec.rb +++ b/spec/lib/gitlab/metrics/subscribers/rails_cache_spec.rb @@ -1,15 +1,16 @@ require 'spec_helper' describe Gitlab::Metrics::Subscribers::RailsCache do - let(:transaction) { Gitlab::Metrics::Transaction.new } + let(:env) { {} } + let(:transaction) { Gitlab::Metrics::WebTransaction.new(env) } let(:subscriber) { described_class.new } let(:event) { double(:event, duration: 15.2) } describe '#cache_read' do it 'increments the cache_read duration' do - expect(subscriber).to receive(:increment) - .with(:cache_read, event.duration) + expect(subscriber).to receive(:observe) + .with(:read, event.duration) subscriber.cache_read(event) end @@ -17,7 +18,7 @@ describe Gitlab::Metrics::Subscribers::RailsCache do context 'with a transaction' do before do allow(subscriber).to receive(:current_transaction) - .and_return(transaction) + .and_return(transaction) end context 'with hit event' do @@ -25,9 +26,9 @@ describe Gitlab::Metrics::Subscribers::RailsCache do it 'increments the cache_read_hit count' do expect(transaction).to receive(:increment) - .with(:cache_read_hit_count, 1) + .with(:cache_read_hit_count, 1, false) expect(transaction).to receive(:increment) - .with(any_args).at_least(1) # Other calls + .with(any_args).at_least(1) # Other calls subscriber.cache_read(event) end @@ -37,7 +38,7 @@ describe Gitlab::Metrics::Subscribers::RailsCache do it 'does not increment cache read miss' do expect(transaction).not_to receive(:increment) - .with(:cache_read_hit_count, 1) + .with(:cache_read_hit_count, 1) subscriber.cache_read(event) end @@ -49,9 +50,15 @@ describe Gitlab::Metrics::Subscribers::RailsCache do it 'increments the cache_read_miss count' do expect(transaction).to receive(:increment) - .with(:cache_read_miss_count, 1) + .with(:cache_read_miss_count, 1, false) expect(transaction).to receive(:increment) - .with(any_args).at_least(1) # Other calls + .with(any_args).at_least(1) # Other calls + + subscriber.cache_read(event) + end + + it 'increments the cache_read_miss total' do + expect(subscriber.send(:metric_cache_misses_total)).to receive(:increment).with({}) subscriber.cache_read(event) end @@ -61,7 +68,13 @@ describe Gitlab::Metrics::Subscribers::RailsCache do it 'does not increment cache read miss' do expect(transaction).not_to receive(:increment) - .with(:cache_read_miss_count, 1) + .with(:cache_read_miss_count, 1) + + subscriber.cache_read(event) + end + + it 'does not increment cache_read_miss total' do + expect(subscriber.send(:metric_cache_misses_total)).not_to receive(:increment).with({}) subscriber.cache_read(event) end @@ -71,27 +84,27 @@ describe Gitlab::Metrics::Subscribers::RailsCache do end describe '#cache_write' do - it 'increments the cache_write duration' do - expect(subscriber).to receive(:increment) - .with(:cache_write, event.duration) + it 'observes write duration' do + expect(subscriber).to receive(:observe) + .with(:write, event.duration) subscriber.cache_write(event) end end describe '#cache_delete' do - it 'increments the cache_delete duration' do - expect(subscriber).to receive(:increment) - .with(:cache_delete, event.duration) + it 'observes delete duration' do + expect(subscriber).to receive(:observe) + .with(:delete, event.duration) subscriber.cache_delete(event) end end describe '#cache_exist?' do - it 'increments the cache_exists duration' do - expect(subscriber).to receive(:increment) - .with(:cache_exists, event.duration) + it 'observes the exists duration' do + expect(subscriber).to receive(:observe) + .with(:exists, event.duration) subscriber.cache_exist?(event) end @@ -109,12 +122,12 @@ describe Gitlab::Metrics::Subscribers::RailsCache do context 'with a transaction' do before do allow(subscriber).to receive(:current_transaction) - .and_return(transaction) + .and_return(transaction) end it 'increments the cache_read_hit count' do expect(transaction).to receive(:increment) - .with(:cache_read_hit_count, 1) + .with(:cache_read_hit_count, 1) subscriber.cache_fetch_hit(event) end @@ -133,47 +146,61 @@ describe Gitlab::Metrics::Subscribers::RailsCache do context 'with a transaction' do before do allow(subscriber).to receive(:current_transaction) - .and_return(transaction) + .and_return(transaction) end it 'increments the cache_fetch_miss count' do expect(transaction).to receive(:increment) - .with(:cache_read_miss_count, 1) + .with(:cache_read_miss_count, 1) + + subscriber.cache_generate(event) + end + + it 'increments the cache_read_miss total' do + expect(subscriber.send(:metric_cache_misses_total)).to receive(:increment).with({}) subscriber.cache_generate(event) end end end - describe '#increment' do + describe '#observe' do context 'without a transaction' do it 'returns' do expect(transaction).not_to receive(:increment) - subscriber.increment(:foo, 15.2) + subscriber.observe(:foo, 15.2) end end context 'with a transaction' do before do allow(subscriber).to receive(:current_transaction) - .and_return(transaction) + .and_return(transaction) end it 'increments the total and specific cache duration' do expect(transaction).to receive(:increment) - .with(:cache_duration, event.duration) + .with(:cache_duration, event.duration, false) expect(transaction).to receive(:increment) - .with(:cache_count, 1) + .with(:cache_count, 1, false) expect(transaction).to receive(:increment) - .with(:cache_delete_duration, event.duration) + .with(:cache_delete_duration, event.duration, false) expect(transaction).to receive(:increment) - .with(:cache_delete_count, 1) + .with(:cache_delete_count, 1, false) + + subscriber.observe(:delete, event.duration) + end + + it 'observes cache metric' do + expect(subscriber.send(:metric_cache_operation_duration_seconds)) + .to receive(:observe) + .with(transaction.labels.merge(operation: :delete), event.duration / 1000.0) - subscriber.increment(:cache_delete, event.duration) + subscriber.observe(:delete, event.duration) end end end diff --git a/spec/lib/gitlab/metrics/transaction_spec.rb b/spec/lib/gitlab/metrics/web_transaction_spec.rb index 3779af81512..1d162f53a13 100644 --- a/spec/lib/gitlab/metrics/transaction_spec.rb +++ b/spec/lib/gitlab/metrics/web_transaction_spec.rb @@ -1,7 +1,8 @@ require 'spec_helper' -describe Gitlab::Metrics::Transaction do - let(:transaction) { described_class.new } +describe Gitlab::Metrics::WebTransaction do + let(:env) { {} } + let(:transaction) { described_class.new(env) } describe '#duration' do it 'returns the duration of a transaction in seconds' do @@ -48,7 +49,7 @@ describe Gitlab::Metrics::Transaction do describe '#method_call_for' do it 'returns a MethodCall' do - method = transaction.method_call_for('Foo#bar') + method = transaction.method_call_for('Foo#bar', :Foo, '#bar') expect(method).to be_an_instance_of(Gitlab::Metrics::MethodCall) end @@ -85,14 +86,6 @@ describe Gitlab::Metrics::Transaction do end end - describe '#add_tag' do - it 'adds a tag' do - transaction.add_tag(:foo, 'bar') - - expect(transaction.tags).to eq({ foo: 'bar' }) - end - end - describe '#finish' do it 'tracks the transaction details and submits them to Sidekiq' do expect(transaction).to receive(:track_self) @@ -127,7 +120,7 @@ describe Gitlab::Metrics::Transaction do end it 'adds the action as a tag for every metric' do - transaction.action = 'Foo#bar' + allow(transaction).to receive(:labels).and_return(controller: 'Foo', action: 'bar') transaction.track_self hash = { @@ -144,7 +137,8 @@ describe Gitlab::Metrics::Transaction do end it 'does not add an action tag for events' do - transaction.action = 'Foo#bar' + allow(transaction).to receive(:labels).and_return(controller: 'Foo', action: 'bar') + transaction.add_event(:meow) hash = { @@ -161,6 +155,61 @@ describe Gitlab::Metrics::Transaction do end end + describe '#labels' do + context 'when request goes to Grape endpoint' do + before do + route = double(:route, request_method: 'GET', path: '/:version/projects/:id/archive(.:format)') + endpoint = double(:endpoint, route: route) + + env['api.endpoint'] = endpoint + end + it 'provides labels with the method and path of the route in the grape endpoint' do + expect(transaction.labels).to eq({ controller: 'Grape', action: 'GET /projects/:id/archive' }) + expect(transaction.action).to eq('Grape#GET /projects/:id/archive') + end + + it 'does not provide labels if route infos are missing' do + endpoint = double(:endpoint) + allow(endpoint).to receive(:route).and_raise + + env['api.endpoint'] = endpoint + + expect(transaction.labels).to eq({}) + expect(transaction.action).to be_nil + end + end + + context 'when request goes to ActionController' do + let(:content_type) { 'text/html' } + + before do + klass = double(:klass, name: 'TestController') + controller = double(:controller, class: klass, action_name: 'show', content_type: content_type) + + env['action_controller.instance'] = controller + end + + it 'tags a transaction with the name and action of a controller' do + expect(transaction.labels).to eq({ controller: 'TestController', action: 'show' }) + expect(transaction.action).to eq('TestController#show') + end + + context 'when the response content type is not :html' do + let(:content_type) { 'application/json' } + + it 'appends the mime type to the transaction action' do + expect(transaction.labels).to eq({ controller: 'TestController', action: 'show.json' }) + expect(transaction.action).to eq('TestController#show.json') + end + end + end + + it 'returns no labels when no route information is present in env' do + expect(transaction.labels).to eq({}) + expect(transaction.action).to eq(nil) + end + end + describe '#add_event' do it 'adds a metric' do transaction.add_event(:meow) diff --git a/spec/lib/gitlab/metrics_spec.rb b/spec/lib/gitlab/metrics_spec.rb index 599b8807d8d..1619fbd88b1 100644 --- a/spec/lib/gitlab/metrics_spec.rb +++ b/spec/lib/gitlab/metrics_spec.rb @@ -115,7 +115,7 @@ describe Gitlab::Metrics do end context 'with a transaction' do - let(:transaction) { Gitlab::Metrics::Transaction.new } + let(:transaction) { Gitlab::Metrics::WebTransaction.new({}) } before do allow(described_class).to receive(:current_transaction) @@ -124,13 +124,13 @@ describe Gitlab::Metrics do it 'adds a metric to the current transaction' do expect(transaction).to receive(:increment) - .with('foo_real_time', a_kind_of(Numeric)) + .with('foo_real_time', a_kind_of(Numeric), false) expect(transaction).to receive(:increment) - .with('foo_cpu_time', a_kind_of(Numeric)) + .with('foo_cpu_time', a_kind_of(Numeric), false) expect(transaction).to receive(:increment) - .with('foo_call_count', 1) + .with('foo_call_count', 1, false) described_class.measure(:foo) { 10 } end @@ -143,31 +143,6 @@ describe Gitlab::Metrics do end end - describe '.tag_transaction' do - context 'without a transaction' do - it 'does nothing' do - expect_any_instance_of(Gitlab::Metrics::Transaction) - .not_to receive(:add_tag) - - described_class.tag_transaction(:foo, 'bar') - end - end - - context 'with a transaction' do - let(:transaction) { Gitlab::Metrics::Transaction.new } - - it 'adds the tag to the transaction' do - expect(described_class).to receive(:current_transaction) - .and_return(transaction) - - expect(transaction).to receive(:add_tag) - .with(:foo, 'bar') - - described_class.tag_transaction(:foo, 'bar') - end - end - end - describe '.action=' do context 'without a transaction' do it 'does nothing' do @@ -180,7 +155,7 @@ describe Gitlab::Metrics do context 'with a transaction' do it 'sets the action of a transaction' do - trans = Gitlab::Metrics::Transaction.new + trans = Gitlab::Metrics::WebTransaction.new({}) expect(described_class).to receive(:current_transaction) .and_return(trans) @@ -210,7 +185,7 @@ describe Gitlab::Metrics do context 'with a transaction' do it 'adds an event' do - transaction = Gitlab::Metrics::Transaction.new + transaction = Gitlab::Metrics::WebTransaction.new({}) expect(transaction).to receive(:add_event).with(:meow) @@ -224,7 +199,7 @@ describe Gitlab::Metrics do shared_examples 'prometheus metrics API' do describe '#counter' do - subject { described_class.counter(:couter, 'doc') } + subject { described_class.counter(:counter, 'doc') } describe '#increment' do it 'successfully calls #increment without arguments' do @@ -280,7 +255,7 @@ describe Gitlab::Metrics do it_behaves_like 'prometheus metrics API' describe '#null_metric' do - subject { described_class.provide_metric(:test) } + subject { described_class.send(:provide_metric, :test) } it { is_expected.to be_a(Gitlab::Metrics::NullMetric) } end @@ -321,7 +296,7 @@ describe Gitlab::Metrics do it_behaves_like 'prometheus metrics API' describe '#null_metric' do - subject { described_class.provide_metric(:test) } + subject { described_class.send(:provide_metric, :test) } it { is_expected.to be_nil } end diff --git a/spec/lib/gitlab/middleware/rails_queue_duration_spec.rb b/spec/lib/gitlab/middleware/rails_queue_duration_spec.rb index 88107536c9e..14f2c3cb86f 100644 --- a/spec/lib/gitlab/middleware/rails_queue_duration_spec.rb +++ b/spec/lib/gitlab/middleware/rails_queue_duration_spec.rb @@ -4,7 +4,7 @@ describe Gitlab::Middleware::RailsQueueDuration do let(:app) { double(:app) } let(:middleware) { described_class.new(app) } let(:env) { {} } - let(:transaction) { double(:transaction) } + let(:transaction) { Gitlab::Metrics::WebTransaction.new(env) } before do expect(app).to receive(:call).with(env).and_return('yay') @@ -30,6 +30,16 @@ describe Gitlab::Middleware::RailsQueueDuration do expect(transaction).to receive(:set).with(:rails_queue_duration, an_instance_of(Float)) expect(middleware.call(env)).to eq('yay') end + + it 'observes rails queue duration metrics and calls the app when the header is present' do + env['HTTP_GITLAB_WORKHORSE_PROXY_START'] = '2000000000' + + expect(middleware.send(:metric_rails_queue_duration_seconds)).to receive(:observe).with(transaction.labels, 1) + + Timecop.freeze(Time.at(3)) do + expect(middleware.call(env)).to eq('yay') + end + end end end end |