diff options
| author | Yorick Peterse <yorickpeterse@gmail.com> | 2015-12-09 16:45:51 +0100 |
|---|---|---|
| committer | Yorick Peterse <yorickpeterse@gmail.com> | 2015-12-17 17:25:48 +0100 |
| commit | 141e946c3da97c7af02aaca5324c6e4ce7362a04 (patch) | |
| tree | 15fc780a8d99785f5ae3b069fa49c38d83e02002 | |
| parent | b2c593dac513c0e12153e0aa786759c4ebc996bc (diff) | |
| download | gitlab-ce-141e946c3da97c7af02aaca5324c6e4ce7362a04.tar.gz | |
Storing of application metrics in InfluxDB
This adds the ability to write application metrics (e.g. SQL timings) to
InfluxDB. These metrics can in turn be visualized using Grafana, or
really anything else that can read from InfluxDB. These metrics can be
used to track application performance over time, between different Ruby
versions, different GitLab versions, etc.
== Transaction Metrics
Currently the following is tracked on a per transaction basis (a
transaction is a Rails request or a single Sidekiq job):
* Timings per query along with the raw (obfuscated) SQL and information
about what file the query originated from.
* Timings per view along with the path of the view and information about
what file triggered the rendering process.
* The duration of a request itself along with the controller/worker
class and method name.
* The duration of any instrumented method calls (more below).
== Sampled Metrics
Certain metrics can't be directly associated with a transaction. For
example, a process' total memory usage is unrelated to any running
transactions. While a transaction can result in the memory usage going
up there's no accurate way to determine what transaction is to blame,
this becomes especially problematic in multi-threaded environments.
To solve this problem there's a separate thread that takes samples at a
fixed interval. This thread (using the class Gitlab::Metrics::Sampler)
currently tracks the following:
* The process' total memory usage.
* The number of file descriptors opened by the process.
* The amount of Ruby objects (using ObjectSpace.count_objects).
* GC statistics such as timings, heap slots, etc.
The default/current interval is 15 seconds, any smaller interval might
put too much pressure on InfluxDB (especially when running dozens of
processes).
== Method Instrumentation
While currently not yet used methods can be instrumented to track how
long they take to run. Unlike the likes of New Relic this doesn't
require modifying the source code (e.g. including modules), it all
happens from the outside. For example, to track `User.by_login` we'd add
the following code somewhere in an initializer:
Gitlab::Metrics::Instrumentation.
instrument_method(User, :by_login)
to instead instrument an instance method:
Gitlab::Metrics::Instrumentation.
instrument_instance_method(User, :save)
Instrumentation for either all public model methods or a few crucial
ones will be added in the near future, I simply haven't gotten to doing
so just yet.
== Configuration
By default metrics are disabled. This means users don't have to bother
setting anything up if they don't want to. Metrics can be enabled by
editing one's gitlab.yml configuration file (see
config/gitlab.yml.example for example settings).
== Writing Data To InfluxDB
Because InfluxDB is still a fairly young product I expect the worse.
Data loss, unexpected reboots, the database not responding, you name it.
Because of this data is _not_ written to InfluxDB directly, instead it's
queued and processed by Sidekiq. This ensures that users won't notice
anything when InfluxDB is giving trouble.
The metrics worker can be started in a standalone manner as following:
bundle exec sidekiq -q metrics
The corresponding class is called MetricsWorker.
32 files changed, 1368 insertions, 13 deletions
@@ -208,6 +208,12 @@ gem 'select2-rails', '~> 3.5.9' gem 'virtus', '~> 1.0.1' gem 'net-ssh', '~> 3.0.1' +# Metrics +group :metrics do + gem 'influxdb', '~> 0.2', require: false + gem 'connection_pool', '~> 2.0', require: false +end + group :development do gem "foreman" gem 'brakeman', '3.0.1', require: false diff --git a/Gemfile.lock b/Gemfile.lock index 4dfff211134..7d592ba93a7 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -65,7 +65,7 @@ GEM attr_encrypted (1.3.4) encryptor (>= 1.3.0) attr_required (1.0.0) - autoprefixer-rails (6.1.1) + autoprefixer-rails (6.1.2) execjs json awesome_print (1.2.0) @@ -102,7 +102,7 @@ GEM bundler-audit (0.4.0) bundler (~> 1.2) thor (~> 0.18) - byebug (8.2.0) + byebug (8.2.1) cal-heatmap-rails (0.0.1) capybara (2.4.4) mime-types (>= 1.16) @@ -117,6 +117,7 @@ GEM activemodel (>= 3.2.0) activesupport (>= 3.2.0) json (>= 1.7) + cause (0.1) charlock_holmes (0.7.3) chunky_png (1.3.5) cliver (0.3.2) @@ -140,10 +141,10 @@ GEM term-ansicolor (~> 1.3) thor (~> 0.19.1) tins (~> 1.6.0) - crack (0.4.2) + crack (0.4.3) safe_yaml (~> 1.0.0) creole (0.5.0) - d3_rails (3.5.6) + d3_rails (3.5.11) railties (>= 3.1.0) daemons (1.2.3) database_cleaner (1.4.1) @@ -230,7 +231,7 @@ GEM ipaddress (~> 0.5) nokogiri (~> 1.5, >= 1.5.11) opennebula - fog-brightbox (0.9.0) + fog-brightbox (0.10.1) fog-core (~> 1.22) fog-json inflecto (~> 0.0.2) @@ -249,7 +250,7 @@ GEM fog-core (>= 1.21.0) fog-json fog-xml (>= 0.0.1) - fog-sakuracloud (1.4.0) + fog-sakuracloud (1.5.0) fog-core fog-json fog-softlayer (1.0.2) @@ -277,11 +278,11 @@ GEM ruby-progressbar (~> 1.4) gemnasium-gitlab-service (0.2.6) rugged (~> 0.21) - gemojione (2.1.0) + gemojione (2.1.1) json get_process_mem (0.2.0) gherkin-ruby (0.3.2) - github-linguist (4.7.2) + github-linguist (4.7.3) charlock_holmes (~> 0.7.3) escape_utils (~> 1.1.0) mime-types (>= 1.19) @@ -298,7 +299,7 @@ GEM posix-spawn (~> 0.3) gitlab_emoji (0.2.0) gemojione (~> 2.1) - gitlab_git (7.2.21) + gitlab_git (7.2.22) activesupport (~> 4.0) charlock_holmes (~> 0.7.3) github-linguist (~> 4.7.0) @@ -370,6 +371,9 @@ GEM i18n (0.7.0) ice_nine (0.11.1) inflecto (0.0.2) + influxdb (0.2.3) + cause + json ipaddress (0.8.0) jquery-atwho-rails (1.3.2) jquery-rails (3.1.4) @@ -416,11 +420,11 @@ GEM net-ldap (0.12.1) net-ssh (3.0.1) netrc (0.11.0) - newrelic-grape (2.0.0) + newrelic-grape (2.1.0) grape newrelic_rpm newrelic_rpm (3.9.4.245) - nokogiri (1.6.7) + nokogiri (1.6.7.1) mini_portile2 (~> 2.0.0.rc2) nprogress-rails (0.1.6.7) oauth (0.4.7) @@ -783,7 +787,7 @@ GEM coercible (~> 1.0) descendants_tracker (~> 0.0, >= 0.0.3) equalizer (~> 0.0, >= 0.0.9) - warden (1.2.3) + warden (1.2.4) rack (>= 1.0) web-console (2.2.1) activemodel (>= 4.0) @@ -836,6 +840,7 @@ DEPENDENCIES charlock_holmes (~> 0.7.3) coffee-rails (~> 4.1.0) colorize (~> 0.7.0) + connection_pool (~> 2.0) coveralls (~> 0.8.2) creole (~> 0.5.0) d3_rails (~> 3.5.5) @@ -873,6 +878,7 @@ DEPENDENCIES hipchat (~> 1.5.0) html-pipeline (~> 1.11.0) httparty (~> 0.13.3) + influxdb (~> 0.2) jquery-atwho-rails (~> 1.3.2) jquery-rails (~> 3.1.3) jquery-scrollto-rails (~> 1.4.3) @@ -3,5 +3,5 @@ # lib/support/init.d, which call scripts in bin/ . # web: bundle exec unicorn_rails -p ${PORT:="3000"} -E ${RAILS_ENV:="development"} -c ${UNICORN_CONFIG:="config/unicorn.rb"} -worker: bundle exec sidekiq -q post_receive -q mailers -q archive_repo -q system_hook -q project_web_hook -q gitlab_shell -q incoming_email -q runner -q common -q default +worker: bundle exec sidekiq -q post_receive -q mailers -q archive_repo -q system_hook -q project_web_hook -q gitlab_shell -q incoming_email -q runner -q common -q default -q metrics # mail_room: bundle exec mail_room -q -c config/mail_room.yml diff --git a/app/workers/metrics_worker.rb b/app/workers/metrics_worker.rb new file mode 100644 index 00000000000..8fffe371572 --- /dev/null +++ b/app/workers/metrics_worker.rb @@ -0,0 +1,29 @@ +class MetricsWorker + include Sidekiq::Worker + + sidekiq_options queue: :metrics + + def perform(metrics) + prepared = prepare_metrics(metrics) + + Gitlab::Metrics.pool.with do |connection| + connection.write_points(prepared) + end + end + + def prepare_metrics(metrics) + metrics.map do |hash| + new_hash = hash.symbolize_keys + + new_hash[:tags].each do |key, value| + new_hash[:tags][key] = escape_value(value) + end + + new_hash + end + end + + def escape_value(value) + value.gsub('=', '\\=') + end +end diff --git a/config/gitlab.yml.example b/config/gitlab.yml.example index db378118f85..38b0920890f 100644 --- a/config/gitlab.yml.example +++ b/config/gitlab.yml.example @@ -421,9 +421,22 @@ production: &base # # Ban an IP for one hour (3600s) after too many auth attempts # bantime: 3600 + metrics: + enabled: false + # The name of the InfluxDB database to store metrics in. + database: gitlab + # Credentials to use for logging in to InfluxDB. + # username: + # password: + # The amount of InfluxDB connections to open. + # pool_size: 16 + # The timeout of a connection in seconds. + # timeout: 10 development: <<: *base + metrics: + enabled: false test: <<: *base @@ -466,6 +479,10 @@ test: user_filter: '' group_base: 'ou=groups,dc=example,dc=com' admin_group: '' + metrics: + enabled: false staging: <<: *base + metrics: + enabled: false diff --git a/config/initializers/metrics.rb b/config/initializers/metrics.rb new file mode 100644 index 00000000000..bde04232725 --- /dev/null +++ b/config/initializers/metrics.rb @@ -0,0 +1,25 @@ +if Gitlab::Metrics.enabled? + require 'influxdb' + require 'socket' + require 'connection_pool' + + # These are manually require'd so the classes are registered properly with + # ActiveSupport. + require 'gitlab/metrics/subscribers/action_view' + require 'gitlab/metrics/subscribers/active_record' + require 'gitlab/metrics/subscribers/method_call' + + Gitlab::Application.configure do |config| + config.middleware.use(Gitlab::Metrics::RackMiddleware) + end + + Sidekiq.configure_server do |config| + config.server_middleware do |chain| + chain.add Gitlab::Metrics::SidekiqMiddleware + end + end + + GC::Profiler.enable + + Gitlab::Metrics::Sampler.new.start +end diff --git a/lib/gitlab/metrics.rb b/lib/gitlab/metrics.rb new file mode 100644 index 00000000000..08393995165 --- /dev/null +++ b/lib/gitlab/metrics.rb @@ -0,0 +1,52 @@ +module Gitlab + module Metrics + def self.pool_size + Settings.metrics['pool_size'] || 16 + end + + def self.timeout + Settings.metrics['timeout'] || 10 + end + + def self.enabled? + !!Settings.metrics['enabled'] + end + + def self.pool + @pool + end + + def self.hostname + @hostname + end + + def self.last_relative_application_frame + root = Rails.root.to_s + metrics = Rails.root.join('lib', 'gitlab', 'metrics').to_s + + frame = caller_locations.find do |l| + l.path.start_with?(root) && !l.path.start_with?(metrics) + end + + if frame + return frame.path.gsub(/^#{Rails.root.to_s}\/?/, ''), frame.lineno + else + return nil, nil + end + end + + @hostname = Socket.gethostname + + # When enabled this should be set before being used as the usual pattern + # "@foo ||= bar" is _not_ thread-safe. + if enabled? + @pool = ConnectionPool.new(size: pool_size, timeout: timeout) do + db = Settings.metrics['database'] + user = Settings.metrics['username'] + pw = Settings.metrics['password'] + + InfluxDB::Client.new(db, username: user, password: pw) + end + end + end +end diff --git a/lib/gitlab/metrics/delta.rb b/lib/gitlab/metrics/delta.rb new file mode 100644 index 00000000000..bcf28eed84d --- /dev/null +++ b/lib/gitlab/metrics/delta.rb @@ -0,0 +1,32 @@ +module Gitlab + module Metrics + # Class for calculating the difference between two numeric values. + # + # Every call to `compared_with` updates the internal value. This makes it + # possible to use a single Delta instance to calculate the delta over time + # of an ever increasing number. + # + # Example usage: + # + # delta = Delta.new(0) + # + # delta.compared_with(10) # => 10 + # delta.compared_with(15) # => 5 + # delta.compared_with(20) # => 5 + class Delta + def initialize(value = 0) + @value = value + end + + # new_value - The value to compare with as a Numeric. + # + # Returns a new Numeric (depending on the type of `new_value`). + def compared_with(new_value) + delta = new_value - @value + @value = new_value + + delta + end + end + end +end diff --git a/lib/gitlab/metrics/instrumentation.rb b/lib/gitlab/metrics/instrumentation.rb new file mode 100644 index 00000000000..1c2f84fb09a --- /dev/null +++ b/lib/gitlab/metrics/instrumentation.rb @@ -0,0 +1,47 @@ +module Gitlab + module Metrics + # Module for instrumenting methods. + # + # This module allows instrumenting of methods without having to actually + # alter the target code (e.g. by including modules). + # + # Example usage: + # + # Gitlab::Metrics::Instrumentation.instrument_method(User, :by_login) + module Instrumentation + # Instruments a class method. + # + # mod - The module to instrument as a Module/Class. + # name - The name of the method to instrument. + def self.instrument_method(mod, name) + instrument(:class, mod, name) + end + + # Instruments an instance method. + # + # mod - The module to instrument as a Module/Class. + # name - The name of the method to instrument. + def self.instrument_instance_method(mod, name) + instrument(:instance, mod, name) + end + + def self.instrument(type, mod, name) + return unless Metrics.enabled? + + alias_name = "_original_#{name}" + target = type == :instance ? mod : mod.singleton_class + + target.class_eval do + alias_method(alias_name, name) + + define_method(name) do |*args, &block| + ActiveSupport::Notifications. + instrument("#{type}_method.method_call", module: mod, name: name) do + __send__(alias_name, *args, &block) + end + end + end + end + end + end +end diff --git a/lib/gitlab/metrics/metric.rb b/lib/gitlab/metrics/metric.rb new file mode 100644 index 00000000000..f592f4e571f --- /dev/null +++ b/lib/gitlab/metrics/metric.rb @@ -0,0 +1,34 @@ +module Gitlab + module Metrics + # Class for storing details of a single metric (label, value, etc). + class Metric + attr_reader :series, :values, :tags, :created_at + + # series - The name of the series (as a String) to store the metric in. + # values - A Hash containing the values to store. + # tags - A Hash containing extra tags to add to the metrics. + def initialize(series, values, tags = {}) + @values = values + @series = series + @tags = tags + @created_at = Time.now.utc + end + + # Returns a Hash in a format that can be directly written to InfluxDB. + def to_hash + { + series: @series, + tags: @tags.merge( + hostname: Metrics.hostname, + ruby_engine: RUBY_ENGINE, + ruby_version: RUBY_VERSION, + gitlab_version: Gitlab::VERSION, + process_type: Sidekiq.server? ? 'sidekiq' : 'rails' + ), + values: @values, + timestamp: @created_at.to_i + } + end + end + end +end diff --git a/lib/gitlab/metrics/obfuscated_sql.rb b/lib/gitlab/metrics/obfuscated_sql.rb new file mode 100644 index 00000000000..45f2e2bc62a --- /dev/null +++ b/lib/gitlab/metrics/obfuscated_sql.rb @@ -0,0 +1,39 @@ +module Gitlab + module Metrics + # Class for producing SQL queries with sensitive data stripped out. + class ObfuscatedSQL + REPLACEMENT = / + \d+(\.\d+)? # integers, floats + | '.+?' # single quoted strings + | \/.+?(?<!\\)\/ # regexps (including escaped slashes) + /x + + MYSQL_REPLACEMENTS = / + ".+?" # double quoted strings + /x + + # Regex to replace consecutive placeholders with a single one indicating + # the length. This can be useful when a "IN" statement uses thousands of + # IDs (storing this would just be a waste of space). + CONSECUTIVE = /(\?(\s*,\s*)?){2,}/ + + # sql - The raw SQL query as a String. + def initialize(sql) + @sql = sql + end + + # Returns a new, obfuscated SQL query. + def to_s + regex = REPLACEMENT + + if Gitlab::Database.mysql? + regex = Regexp.union(regex, MYSQL_REPLACEMENTS) + end + + @sql.gsub(regex, '?').gsub(CONSECUTIVE) do |match| + "#{match.count(',') + 1} values" + end + end + end + end +end diff --git a/lib/gitlab/metrics/rack_middleware.rb b/lib/gitlab/metrics/rack_middleware.rb new file mode 100644 index 00000000000..5c0587c4c51 --- /dev/null +++ b/lib/gitlab/metrics/rack_middleware.rb @@ -0,0 +1,49 @@ +module Gitlab + module Metrics + # Rack middleware for tracking Rails requests. + class RackMiddleware + CONTROLLER_KEY = 'action_controller.instance' + + def initialize(app) + @app = app + end + + # env - A Hash containing Rack environment details. + def call(env) + trans = transaction_from_env(env) + retval = nil + + begin + retval = trans.run { @app.call(env) } + + # 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) + end + + trans.finish + end + + retval + end + + def transaction_from_env(env) + trans = Transaction.new + + trans.add_tag(:request_method, env['REQUEST_METHOD']) + trans.add_tag(:request_uri, env['REQUEST_URI']) + + trans + end + + def tag_controller(trans, env) + controller = env[CONTROLLER_KEY] + label = "#{controller.class.name}##{controller.action_name}" + + trans.add_tag(:action, label) + end + end + end +end diff --git a/lib/gitlab/metrics/sampler.rb b/lib/gitlab/metrics/sampler.rb new file mode 100644 index 00000000000..141953dc985 --- /dev/null +++ b/lib/gitlab/metrics/sampler.rb @@ -0,0 +1,77 @@ +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 Sampler + # interval - The sampling interval in seconds. + def initialize(interval = 15) + @interval = interval + @metrics = [] + + @last_minor_gc = Delta.new(GC.stat[:minor_gc_count]) + @last_major_gc = Delta.new(GC.stat[:major_gc_count]) + end + + def start + Thread.new do + Thread.current.abort_on_exception = true + + loop do + sleep(@interval) + + sample + end + end + end + + def sample + sample_memory_usage + sample_file_descriptors + sample_objects + sample_gc + + flush + ensure + GC::Profiler.clear + @metrics.clear + end + + def flush + MetricsWorker.perform_async(@metrics.map(&:to_hash)) + end + + def sample_memory_usage + @metrics << Metric.new('memory_usage', value: System.memory_usage) + end + + def sample_file_descriptors + @metrics << Metric. + new('file_descriptors', value: System.file_descriptor_count) + end + + def sample_objects + @metrics << Metric.new('object_counts', ObjectSpace.count_objects) + 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] + + @metrics << Metric.new('gc_statistics', stats) + end + end + end +end diff --git a/lib/gitlab/metrics/sidekiq_middleware.rb b/lib/gitlab/metrics/sidekiq_middleware.rb new file mode 100644 index 00000000000..ec10707d1fb --- /dev/null +++ b/lib/gitlab/metrics/sidekiq_middleware.rb @@ -0,0 +1,30 @@ +module Gitlab + module Metrics + # Sidekiq middleware for tracking jobs. + # + # This middleware is intended to be used as a server-side middleware. + class SidekiqMiddleware + def call(worker, message, queue) + # We don't want to track the MetricsWorker itself as otherwise we'll end + # up in an infinite loop. + if worker.class == MetricsWorker + yield + return + end + + trans = Transaction.new + + begin + trans.run { yield } + ensure + tag_worker(trans, worker) + trans.finish + end + end + + def tag_worker(trans, worker) + trans.add_tag(:action, "#{worker.class.name}#perform") + end + end + end +end diff --git a/lib/gitlab/metrics/subscribers/action_view.rb b/lib/gitlab/metrics/subscribers/action_view.rb new file mode 100644 index 00000000000..2e88e4bea6a --- /dev/null +++ b/lib/gitlab/metrics/subscribers/action_view.rb @@ -0,0 +1,48 @@ +module Gitlab + module Metrics + module Subscribers + # Class for tracking the rendering timings of views. + class ActionView < ActiveSupport::Subscriber + attach_to :action_view + + SERIES = 'views' + + def render_template(event) + track(event) if current_transaction + end + + alias_method :render_view, :render_template + + private + + def track(event) + path = relative_path(event.payload[:identifier]) + values = values_for(event) + + current_transaction.add_metric(SERIES, values, path: path) + end + + def relative_path(path) + path.gsub(/^#{Rails.root.to_s}\/?/, '') + end + + def values_for(event) + values = { duration: event.duration } + + file, line = Metrics.last_relative_application_frame + + if file and line + values[:file] = file + values[:line] = line + end + + values + end + + def current_transaction + Transaction.current + end + end + end + end +end diff --git a/lib/gitlab/metrics/subscribers/active_record.rb b/lib/gitlab/metrics/subscribers/active_record.rb new file mode 100644 index 00000000000..3cc9b1addf6 --- /dev/null +++ b/lib/gitlab/metrics/subscribers/active_record.rb @@ -0,0 +1,43 @@ +module Gitlab + module Metrics + module Subscribers + # Class for tracking raw SQL queries. + # + # Queries are obfuscated before being logged to ensure no private data is + # exposed via InfluxDB/Grafana. + class ActiveRecord < ActiveSupport::Subscriber + attach_to :active_record + + SERIES = 'sql_queries' + + def sql(event) + return unless current_transaction + + sql = ObfuscatedSQL.new(event.payload[:sql]).to_s + values = values_for(event) + + current_transaction.add_metric(SERIES, values, sql: sql) + end + + private + + def values_for(event) + values = { duration: event.duration } + + file, line = Metrics.last_relative_application_frame + + if file and line + values[:file] = file + values[:line] = line + end + + values + end + + def current_transaction + Transaction.current + end + end + end + end +end diff --git a/lib/gitlab/metrics/subscribers/method_call.rb b/lib/gitlab/metrics/subscribers/method_call.rb new file mode 100644 index 00000000000..1606134b7e5 --- /dev/null +++ b/lib/gitlab/metrics/subscribers/method_call.rb @@ -0,0 +1,42 @@ +module Gitlab + module Metrics + module Subscribers + # Class for tracking method call timings. + class MethodCall < ActiveSupport::Subscriber + attach_to :method_call + + SERIES = 'method_calls' + + def instance_method(event) + return unless current_transaction + + label = "#{event.payload[:module].name}##{event.payload[:name]}" + + add_metric(label, event.duration) + end + + def class_method(event) + return unless current_transaction + + label = "#{event.payload[:module].name}.#{event.payload[:name]}" + + add_metric(label, event.duration) + end + + private + + def add_metric(label, duration) + file, line = Metrics.last_relative_application_frame + + values = { duration: duration, file: file, line: line } + + current_transaction.add_metric(SERIES, values, method: label) + end + + def current_transaction + Transaction.current + end + end + end + end +end diff --git a/lib/gitlab/metrics/system.rb b/lib/gitlab/metrics/system.rb new file mode 100644 index 00000000000..83371265278 --- /dev/null +++ b/lib/gitlab/metrics/system.rb @@ -0,0 +1,35 @@ +module Gitlab + module Metrics + # Module for gathering system/process statistics such as the memory usage. + # + # This module relies on the /proc filesystem being available. If /proc is + # not available the methods of this module will be stubbed. + module System + if File.exist?('/proc') + # Returns the current process' memory usage in bytes. + def self.memory_usage + mem = 0 + match = File.read('/proc/self/status').match(/VmRSS:\s+(\d+)/) + + if match and match[1] + mem = match[1].to_f * 1024 + end + + mem + end + + def self.file_descriptor_count + Dir.glob('/proc/self/fd/*').length + end + else + def self.memory_usage + 0.0 + end + + def self.file_descriptor_count + 0 + end + end + end + end +end diff --git a/lib/gitlab/metrics/transaction.rb b/lib/gitlab/metrics/transaction.rb new file mode 100644 index 00000000000..568f9d6ae0c --- /dev/null +++ b/lib/gitlab/metrics/transaction.rb @@ -0,0 +1,66 @@ +module Gitlab + module Metrics + # Class for storing metrics information of a single transaction. + class Transaction + THREAD_KEY = :_gitlab_metrics_transaction + + SERIES = 'transactions' + + attr_reader :uuid, :tags + + def self.current + Thread.current[THREAD_KEY] + end + + # name - The name of this transaction as a String. + def initialize + @metrics = [] + @uuid = SecureRandom.uuid + + @started_at = nil + @finished_at = nil + + @tags = {} + end + + def duration + @finished_at ? (@finished_at - @started_at) * 1000.0 : 0.0 + end + + def run + Thread.current[THREAD_KEY] = self + + @started_at = Time.now + + yield + ensure + @finished_at = Time.now + + Thread.current[THREAD_KEY] = nil + end + + def add_metric(series, values, tags = {}) + tags = tags.merge(transaction_id: @uuid) + + @metrics << Metric.new(series, values, tags) + end + + def add_tag(key, value) + @tags[key] = value + end + + def finish + track_self + submit + end + + def track_self + add_metric(SERIES, { duration: duration }, @tags) + end + + def submit + MetricsWorker.perform_async(@metrics.map(&:to_hash)) + end + end + end +end diff --git a/spec/lib/gitlab/metrics/delta_spec.rb b/spec/lib/gitlab/metrics/delta_spec.rb new file mode 100644 index 00000000000..718387cdee1 --- /dev/null +++ b/spec/lib/gitlab/metrics/delta_spec.rb @@ -0,0 +1,16 @@ +require 'spec_helper' + +describe Gitlab::Metrics::Delta do + let(:delta) { described_class.new } + + describe '#compared_with' do + it 'returns the delta as a Numeric' do + expect(delta.compared_with(5)).to eq(5) + end + + it 'bases the delta on a previously used value' do + expect(delta.compared_with(5)).to eq(5) + expect(delta.compared_with(15)).to eq(10) + end + end +end diff --git a/spec/lib/gitlab/metrics/instrumentation_spec.rb b/spec/lib/gitlab/metrics/instrumentation_spec.rb new file mode 100644 index 00000000000..eb31c9e52cd --- /dev/null +++ b/spec/lib/gitlab/metrics/instrumentation_spec.rb @@ -0,0 +1,91 @@ +require 'spec_helper' + +describe Gitlab::Metrics::Instrumentation do + before do + @dummy = Class.new do + def self.foo(text = 'foo') + text + end + + def bar(text = 'bar') + text + end + end + end + + describe '.instrument_method' do + describe 'with metrics enabled' do + before do + allow(Gitlab::Metrics).to receive(:enabled?).and_return(true) + + Gitlab::Metrics::Instrumentation.instrument_method(@dummy, :foo) + end + + it 'renames the original method' do + expect(@dummy).to respond_to(:_original_foo) + end + + it 'calls the instrumented method with the correct arguments' do + expect(@dummy.foo).to eq('foo') + end + + it 'fires an ActiveSupport notification upon calling the method' do + expect(ActiveSupport::Notifications).to receive(:instrument). + with('class_method.method_call', module: @dummy, name: :foo) + + @dummy.foo + end + end + + describe 'with metrics disabled' do + before do + allow(Gitlab::Metrics).to receive(:enabled?).and_return(false) + end + + it 'does not instrument the method' do + Gitlab::Metrics::Instrumentation.instrument_method(@dummy, :foo) + + expect(@dummy).to_not respond_to(:_original_foo) + end + end + end + + describe '.instrument_instance_method' do + describe 'with metrics enabled' do + before do + allow(Gitlab::Metrics).to receive(:enabled?).and_return(true) + + Gitlab::Metrics::Instrumentation. + instrument_instance_method(@dummy, :bar) + end + + it 'renames the original method' do + expect(@dummy.method_defined?(:_original_bar)).to eq(true) + end + + it 'calls the instrumented method with the correct arguments' do + expect(@dummy.new.bar).to eq('bar') + end + + it 'fires an ActiveSupport notification upon calling the method' do + expect(ActiveSupport::Notifications).to receive(:instrument). + with('instance_method.method_call', module: @dummy, name: :bar) + + @dummy.new.bar + end + end + + describe 'with metrics disabled' do + before do + allow(Gitlab::Metrics).to receive(:enabled?).and_return(false) + end + + it 'does not instrument the method' do + Gitlab::Metrics::Instrumentation. + instrument_instance_method(@dummy, :bar) + + expect(@dummy.method_defined?(:_original_bar)).to eq(false) + end + end + end +end diff --git a/spec/lib/gitlab/metrics/metric_spec.rb b/spec/lib/gitlab/metrics/metric_spec.rb new file mode 100644 index 00000000000..ec39bc9cce8 --- /dev/null +++ b/spec/lib/gitlab/metrics/metric_spec.rb @@ -0,0 +1,57 @@ +require 'spec_helper' + +describe Gitlab::Metrics::Metric do + let(:metric) do + described_class.new('foo', { number: 10 }, { host: 'localtoast' }) + end + + describe '#series' do + subject { metric.series } + + it { is_expected.to eq('foo') } + end + + describe '#values' do + subject { metric.values } + + it { is_expected.to eq({ number: 10 }) } + end + + describe '#tags' do + subject { metric.tags } + + it { is_expected.to eq({ host: 'localtoast' }) } + end + + describe '#to_hash' do + it 'returns a Hash' do + expect(metric.to_hash).to be_an_instance_of(Hash) + end + + describe 'the returned Hash' do + let(:hash) { metric.to_hash } + + it 'includes the series' do + expect(hash[:series]).to eq('foo') + end + + it 'includes the tags' do + expect(hash[:tags]).to be_an_instance_of(Hash) + + expect(hash[:tags][:hostname]).to be_an_instance_of(String) + expect(hash[:tags][:ruby_engine]).to be_an_instance_of(String) + expect(hash[:tags][:ruby_version]).to be_an_instance_of(String) + expect(hash[:tags][:gitlab_version]).to be_an_instance_of(String) + expect(hash[:tags][:process_type]).to be_an_instance_of(String) + end + + it 'includes the values' do + expect(hash[:values]).to eq({ number: 10 }) + end + + it 'includes the timestamp' do + expect(hash[:timestamp]).to be_an_instance_of(Fixnum) + end + end + end +end diff --git a/spec/lib/gitlab/metrics/obfuscated_sql_spec.rb b/spec/lib/gitlab/metrics/obfuscated_sql_spec.rb new file mode 100644 index 00000000000..6e9b62016d6 --- /dev/null +++ b/spec/lib/gitlab/metrics/obfuscated_sql_spec.rb @@ -0,0 +1,79 @@ +require 'spec_helper' + +describe Gitlab::Metrics::ObfuscatedSQL do + describe '#to_s' do + describe 'using single values' do + it 'replaces a single integer' do + sql = described_class.new('SELECT x FROM y WHERE a = 10') + + expect(sql.to_s).to eq('SELECT x FROM y WHERE a = ?') + end + + it 'replaces a single float' do + sql = described_class.new('SELECT x FROM y WHERE a = 10.5') + + expect(sql.to_s).to eq('SELECT x FROM y WHERE a = ?') + end + + it 'replaces a single quoted string' do + sql = described_class.new("SELECT x FROM y WHERE a = 'foo'") + + expect(sql.to_s).to eq('SELECT x FROM y WHERE a = ?') + end + + if Gitlab::Database.mysql? + it 'replaces a double quoted string' do + sql = described_class.new('SELECT x FROM y WHERE a = "foo"') + + expect(sql.to_s).to eq('SELECT x FROM y WHERE a = ?') + end + end + + it 'replaces a single regular expression' do + sql = described_class.new('SELECT x FROM y WHERE a = /foo/') + + expect(sql.to_s).to eq('SELECT x FROM y WHERE a = ?') + end + + it 'replaces regular expressions using escaped slashes' do + sql = described_class.new('SELECT x FROM y WHERE a = /foo\/bar/') + + expect(sql.to_s).to eq('SELECT x FROM y WHERE a = ?') + end + end + + describe 'using consecutive values' do + it 'replaces multiple integers' do + sql = described_class.new('SELECT x FROM y WHERE z IN (10, 20, 30)') + + expect(sql.to_s).to eq('SELECT x FROM y WHERE z IN (3 values)') + end + + it 'replaces multiple floats' do + sql = described_class.new('SELECT x FROM y WHERE z IN (1.5, 2.5, 3.5)') + + expect(sql.to_s).to eq('SELECT x FROM y WHERE z IN (3 values)') + end + + it 'replaces multiple single quoted strings' do + sql = described_class.new("SELECT x FROM y WHERE z IN ('foo', 'bar')") + + expect(sql.to_s).to eq('SELECT x FROM y WHERE z IN (2 values)') + end + + if Gitlab::Database.mysql? + it 'replaces multiple double quoted strings' do + sql = described_class.new('SELECT x FROM y WHERE z IN ("foo", "bar")') + + expect(sql.to_s).to eq('SELECT x FROM y WHERE z IN (2 values)') + end + end + + it 'replaces multiple regular expressions' do + sql = described_class.new('SELECT x FROM y WHERE z IN (/foo/, /bar/)') + + expect(sql.to_s).to eq('SELECT x FROM y WHERE z IN (2 values)') + end + end + end +end diff --git a/spec/lib/gitlab/metrics/rack_middleware_spec.rb b/spec/lib/gitlab/metrics/rack_middleware_spec.rb new file mode 100644 index 00000000000..a143fe4cfcd --- /dev/null +++ b/spec/lib/gitlab/metrics/rack_middleware_spec.rb @@ -0,0 +1,63 @@ +require 'spec_helper' + +describe Gitlab::Metrics::RackMiddleware do + let(:app) { double(:app) } + + let(:middleware) { described_class.new(app) } + + let(:env) { { 'REQUEST_METHOD' => 'GET', 'REQUEST_URI' => '/foo' } } + + describe '#call' do + before do + expect_any_instance_of(Gitlab::Metrics::Transaction).to receive(:finish) + end + + it 'tracks a transaction' do + expect(app).to receive(:call).with(env).and_return('yay') + + 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') + 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 + end + + describe '#transaction_from_env' do + let(:transaction) { middleware.transaction_from_env(env) } + + it 'returns a Transaction' do + expect(transaction).to be_an_instance_of(Gitlab::Metrics::Transaction) + end + + it 'tags the transaction with the request method and URI' do + expect(transaction.tags[:request_method]).to eq('GET') + expect(transaction.tags[:request_uri]).to eq('/foo') + end + end + + describe '#tag_controller' do + let(:transaction) { middleware.transaction_from_env(env) } + + it 'tags a transaction with the name and action of a controller' do + klass = double(:klass, name: 'TestController') + controller = double(:controller, class: klass, action_name: 'show') + + env['action_controller.instance'] = controller + + middleware.tag_controller(transaction, env) + + expect(transaction.tags[:action]).to eq('TestController#show') + end + end +end diff --git a/spec/lib/gitlab/metrics/sampler_spec.rb b/spec/lib/gitlab/metrics/sampler_spec.rb new file mode 100644 index 00000000000..b486d38870f --- /dev/null +++ b/spec/lib/gitlab/metrics/sampler_spec.rb @@ -0,0 +1,92 @@ +require 'spec_helper' + +describe Gitlab::Metrics::Sampler do + let(:sampler) { described_class.new(5) } + + describe '#start' do + it 'gathers a sample at a given interval' do + expect(sampler).to receive(:sleep).with(5) + expect(sampler).to receive(:sample) + expect(sampler).to receive(:loop).and_yield + + sampler.start.join + end + end + + describe '#sample' do + it 'samples various statistics' do + expect(sampler).to receive(:sample_memory_usage) + expect(sampler).to receive(:sample_file_descriptors) + expect(sampler).to receive(:sample_objects) + expect(sampler).to receive(:sample_gc) + expect(sampler).to receive(:flush) + + sampler.sample + end + + it 'clears any GC profiles' do + expect(sampler).to receive(:flush) + expect(GC::Profiler).to receive(:clear) + + sampler.sample + end + end + + describe '#flush' do + it 'schedules the metrics using Sidekiq' do + expect(MetricsWorker).to receive(:perform_async). + with([an_instance_of(Hash)]) + + sampler.sample_memory_usage + sampler.flush + end + end + + describe '#sample_memory_usage' do + it 'adds a metric containing the memory usage' do + expect(Gitlab::Metrics::System).to receive(:memory_usage). + and_return(9000) + + expect(Gitlab::Metrics::Metric).to receive(:new). + with('memory_usage', value: 9000). + and_call_original + + sampler.sample_memory_usage + end + end + + describe '#sample_file_descriptors' do + 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(Gitlab::Metrics::Metric).to receive(:new). + with('file_descriptors', value: 4). + and_call_original + + sampler.sample_file_descriptors + end + end + + describe '#sample_objects' do + it 'adds a metric containing the amount of allocated objects' do + expect(Gitlab::Metrics::Metric).to receive(:new). + with('object_counts', an_instance_of(Hash)). + and_call_original + + sampler.sample_objects + end + end + + describe '#sample_gc' do + it 'adds a metric containing garbage collection statistics' do + expect(GC::Profiler).to receive(:total_time).and_return(0.24) + + expect(Gitlab::Metrics::Metric).to receive(:new). + with('gc_statistics', an_instance_of(Hash)). + and_call_original + + sampler.sample_gc + end + end +end diff --git a/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb b/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb new file mode 100644 index 00000000000..05214efc565 --- /dev/null +++ b/spec/lib/gitlab/metrics/sidekiq_middleware_spec.rb @@ -0,0 +1,34 @@ +require 'spec_helper' + +describe Gitlab::Metrics::SidekiqMiddleware do + let(:middleware) { described_class.new } + + describe '#call' do + it 'tracks the transaction' do + worker = Class.new.new + + expect_any_instance_of(Gitlab::Metrics::Transaction).to receive(:finish) + + middleware.call(worker, 'test', :test) { nil } + end + + it 'does not track jobs of the MetricsWorker' do + worker = MetricsWorker.new + + expect(Gitlab::Metrics::Transaction).to_not receive(:new) + + middleware.call(worker, 'test', :test) { nil } + end + end + + describe '#tag_worker' do + it 'adds the worker class and action to the transaction' do + trans = Gitlab::Metrics::Transaction.new + worker = double(:worker, class: double(:class, name: 'TestWorker')) + + expect(trans).to receive(:add_tag).with(:action, 'TestWorker#perform') + + middleware.tag_worker(trans, worker) + 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 new file mode 100644 index 00000000000..77f3e69d523 --- /dev/null +++ b/spec/lib/gitlab/metrics/subscribers/action_view_spec.rb @@ -0,0 +1,32 @@ +require 'spec_helper' + +describe Gitlab::Metrics::Subscribers::ActionView do + let(:transaction) { Gitlab::Metrics::Transaction.new } + + let(:subscriber) { described_class.new } + + let(:event) do + root = Rails.root.to_s + + double(:event, duration: 2.1, + payload: { identifier: "#{root}/app/views/x.html.haml" }) + end + + before do + allow(subscriber).to receive(:current_transaction).and_return(transaction) + + allow(Gitlab::Metrics).to receive(:last_relative_application_frame). + and_return(['app/views/x.html.haml', 4]) + end + + describe '#render_template' do + it 'tracks rendering of a template' do + values = { duration: 2.1, file: 'app/views/x.html.haml', line: 4 } + + expect(transaction).to receive(:add_metric). + with(described_class::SERIES, values, path: 'app/views/x.html.haml') + + 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 new file mode 100644 index 00000000000..58e8e84df9b --- /dev/null +++ b/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb @@ -0,0 +1,31 @@ +require 'spec_helper' + +describe Gitlab::Metrics::Subscribers::ActiveRecord do + let(:transaction) { Gitlab::Metrics::Transaction.new } + + let(:subscriber) { described_class.new } + + let(:event) do + double(:event, duration: 0.2, + payload: { sql: 'SELECT * FROM users WHERE id = 10' }) + end + + before do + allow(subscriber).to receive(:current_transaction).and_return(transaction) + + allow(Gitlab::Metrics).to receive(:last_relative_application_frame). + and_return(['app/models/foo.rb', 4]) + end + + describe '#sql' do + it 'tracks the execution of a SQL query' do + values = { duration: 0.2, file: 'app/models/foo.rb', line: 4 } + sql = 'SELECT * FROM users WHERE id = ?' + + expect(transaction).to receive(:add_metric). + with(described_class::SERIES, values, sql: sql) + + subscriber.sql(event) + end + end +end diff --git a/spec/lib/gitlab/metrics/subscribers/method_call_spec.rb b/spec/lib/gitlab/metrics/subscribers/method_call_spec.rb new file mode 100644 index 00000000000..65de95d6d1e --- /dev/null +++ b/spec/lib/gitlab/metrics/subscribers/method_call_spec.rb @@ -0,0 +1,41 @@ +require 'spec_helper' + +describe Gitlab::Metrics::Subscribers::MethodCall do + let(:transaction) { Gitlab::Metrics::Transaction.new } + + let(:subscriber) { described_class.new } + + let(:event) do + double(:event, duration: 0.2, + payload: { module: double(:mod, name: 'Foo'), name: :foo }) + end + + before do + allow(subscriber).to receive(:current_transaction).and_return(transaction) + + allow(Gitlab::Metrics).to receive(:last_relative_application_frame). + and_return(['app/models/foo.rb', 4]) + end + + describe '#instance_method' do + it 'tracks the execution of an instance method' do + values = { duration: 0.2, file: 'app/models/foo.rb', line: 4 } + + expect(transaction).to receive(:add_metric). + with(described_class::SERIES, values, method: 'Foo#foo') + + subscriber.instance_method(event) + end + end + + describe '#class_method' do + it 'tracks the execution of a class method' do + values = { duration: 0.2, file: 'app/models/foo.rb', line: 4 } + + expect(transaction).to receive(:add_metric). + with(described_class::SERIES, values, method: 'Foo.foo') + + subscriber.class_method(event) + end + end +end diff --git a/spec/lib/gitlab/metrics/system_spec.rb b/spec/lib/gitlab/metrics/system_spec.rb new file mode 100644 index 00000000000..f8c1d956ca1 --- /dev/null +++ b/spec/lib/gitlab/metrics/system_spec.rb @@ -0,0 +1,29 @@ +require 'spec_helper' + +describe Gitlab::Metrics::System do + if File.exist?('/proc') + describe '.memory_usage' do + it "returns the process' memory usage in bytes" do + expect(described_class.memory_usage).to be > 0 + end + end + + describe '.file_descriptor_count' do + it 'returns the amount of open file descriptors' do + expect(described_class.file_descriptor_count).to be > 0 + end + end + else + describe '.memory_usage' do + it 'returns 0.0' do + expect(described_class.memory_usage).to eq(0.0) + end + end + + describe '.file_descriptor_count' do + it 'returns 0' do + expect(described_class.file_descriptor_count).to eq(0) + end + end + end +end diff --git a/spec/lib/gitlab/metrics/transaction_spec.rb b/spec/lib/gitlab/metrics/transaction_spec.rb new file mode 100644 index 00000000000..5f17ff8ee75 --- /dev/null +++ b/spec/lib/gitlab/metrics/transaction_spec.rb @@ -0,0 +1,77 @@ +require 'spec_helper' + +describe Gitlab::Metrics::Transaction do + let(:transaction) { described_class.new } + + describe '#duration' do + it 'returns the duration of a transaction in seconds' do + transaction.run { sleep(0.5) } + + expect(transaction.duration).to be >= 0.5 + end + end + + describe '#run' do + it 'yields the supplied block' do + expect { |b| transaction.run(&b) }.to yield_control + end + + it 'stores the transaction in the current thread' do + transaction.run do + expect(Thread.current[described_class::THREAD_KEY]).to eq(transaction) + end + end + + it 'removes the transaction from the current thread upon completion' do + transaction.run { } + + expect(Thread.current[described_class::THREAD_KEY]).to be_nil + end + end + + describe '#add_metric' do + it 'adds a metric tagged with the transaction UUID' do + expect(Gitlab::Metrics::Metric).to receive(:new). + with('foo', { number: 10 }, { transaction_id: transaction.uuid }) + + transaction.add_metric('foo', number: 10) + 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) + expect(transaction).to receive(:submit) + + transaction.finish + end + end + + describe '#track_self' do + it 'adds a metric for the transaction itself' do + expect(transaction).to receive(:add_metric). + with(described_class::SERIES, { duration: transaction.duration }, {}) + + transaction.track_self + end + end + + describe '#submit' do + it 'submits the metrics to Sidekiq' do + transaction.track_self + + expect(MetricsWorker).to receive(:perform_async). + with([an_instance_of(Hash)]) + + transaction.submit + end + end +end diff --git a/spec/lib/gitlab/metrics_spec.rb b/spec/lib/gitlab/metrics_spec.rb new file mode 100644 index 00000000000..ebc69f8a75f --- /dev/null +++ b/spec/lib/gitlab/metrics_spec.rb @@ -0,0 +1,36 @@ +require 'spec_helper' + +describe Gitlab::Metrics do + describe '.pool_size' do + it 'returns a Fixnum' do + expect(described_class.pool_size).to be_an_instance_of(Fixnum) + end + end + + describe '.timeout' do + it 'returns a Fixnum' do + expect(described_class.timeout).to be_an_instance_of(Fixnum) + end + end + + describe '.enabled?' do + it 'returns a boolean' do + expect([true, false].include?(described_class.enabled?)).to eq(true) + end + end + + describe '.hostname' do + it 'returns a String containing the hostname' do + expect(described_class.hostname).to eq(Socket.gethostname) + end + end + + describe '.last_relative_application_frame' do + it 'returns an Array containing a file path and line number' do + file, line = described_class.last_relative_application_frame + + expect(line).to eq(30) + expect(file).to eq('spec/lib/gitlab/metrics_spec.rb') + end + end +end |