diff options
Diffstat (limited to 'lib/gitlab/sherlock')
-rw-r--r-- | lib/gitlab/sherlock/collection.rb | 42 | ||||
-rw-r--r-- | lib/gitlab/sherlock/file_sample.rb | 27 | ||||
-rw-r--r-- | lib/gitlab/sherlock/line_profiler.rb | 60 | ||||
-rw-r--r-- | lib/gitlab/sherlock/line_sample.rb | 20 | ||||
-rw-r--r-- | lib/gitlab/sherlock/location.rb | 22 | ||||
-rw-r--r-- | lib/gitlab/sherlock/middleware.rb | 36 | ||||
-rw-r--r-- | lib/gitlab/sherlock/query.rb | 96 | ||||
-rw-r--r-- | lib/gitlab/sherlock/transaction.rb | 85 |
8 files changed, 388 insertions, 0 deletions
diff --git a/lib/gitlab/sherlock/collection.rb b/lib/gitlab/sherlock/collection.rb new file mode 100644 index 00000000000..accdc6469bc --- /dev/null +++ b/lib/gitlab/sherlock/collection.rb @@ -0,0 +1,42 @@ +module Gitlab + module Sherlock + class Collection + include Enumerable + + def initialize + @transactions = [] + @mutex = Mutex.new + end + + def add(transaction) + synchronize { @transactions << transaction } + end + + alias_method :<<, :add + + def each(&block) + synchronize { @transactions.each(&block) } + end + + def clear + synchronize { @transactions.clear } + end + + def empty? + synchronize { @transactions.empty? } + end + + def find_transaction(id) + find { |trans| trans.id == id } + end + + def newest_first + sort { |a, b| b.finished_at <=> a.finished_at } + end + + def synchronize(&block) + @mutex.synchronize(&block) + end + end + end +end diff --git a/lib/gitlab/sherlock/file_sample.rb b/lib/gitlab/sherlock/file_sample.rb new file mode 100644 index 00000000000..7a220de9abc --- /dev/null +++ b/lib/gitlab/sherlock/file_sample.rb @@ -0,0 +1,27 @@ +module Gitlab + module Sherlock + class FileSample + attr_reader :id, :file, :line_samples, :events, :duration + + def initialize(file, line_samples, duration, events) + @id = SecureRandom.uuid + @file = file + @line_samples = line_samples + @duration = duration + @events = events + end + + def relative_path + @relative_path ||= @file.gsub(/^#{Rails.root.to_s}\/?/, '') + end + + def to_param + @id + end + + def source + @source ||= File.read(@file) + end + end + end +end diff --git a/lib/gitlab/sherlock/line_profiler.rb b/lib/gitlab/sherlock/line_profiler.rb new file mode 100644 index 00000000000..a191b1e646d --- /dev/null +++ b/lib/gitlab/sherlock/line_profiler.rb @@ -0,0 +1,60 @@ +module Gitlab + module Sherlock + class LineProfiler + # The minimum amount of time that has to be spent in a file for it to be + # included in a list of samples. + MINIMUM_DURATION = 10.0 + + def profile(&block) + if RUBY_ENGINE == 'ruby' + profile_mri(&block) + else + raise NotImplementedError, + 'Line profiling is not supported on this platform' + end + end + + def profile_mri + retval = nil + samples = lineprof(/^#{Rails.root.to_s}/) { retval = yield } + + file_samples = aggregate_rblineprof(samples) + + [retval, file_samples] + end + + # Returns an Array of file samples based on the output of rblineprof. + def aggregate_rblineprof(lineprof_stats) + samples = [] + + lineprof_stats.each do |(file, stats)| + source_lines = File.read(file).each_line.to_a + line_samples = [] + + total_duration = microsec_to_millisec(stats[0][0]) + total_events = stats[0][2] + + next if total_duration <= MINIMUM_DURATION + + stats[1..-1].each_with_index do |data, index| + next unless source_lines[index] + + duration = microsec_to_millisec(data[0]) + events = data[2] + + line_samples << LineSample.new(duration, events) + end + + samples << FileSample. + new(file, line_samples, total_duration, total_events) + end + + samples + end + + def microsec_to_millisec(microsec) + microsec / 1000.0 + end + end + end +end diff --git a/lib/gitlab/sherlock/line_sample.rb b/lib/gitlab/sherlock/line_sample.rb new file mode 100644 index 00000000000..38df7a88e4e --- /dev/null +++ b/lib/gitlab/sherlock/line_sample.rb @@ -0,0 +1,20 @@ +module Gitlab + module Sherlock + class LineSample + attr_reader :duration, :events + + def initialize(duration, events) + @duration = duration + @events = events + end + + def percentage_of(total_duration) + (duration.to_f / total_duration) * 100.0 + end + + def majority_of?(total_duration) + percentage_of(total_duration) >= 30 + end + end + end +end diff --git a/lib/gitlab/sherlock/location.rb b/lib/gitlab/sherlock/location.rb new file mode 100644 index 00000000000..8c0b77dce1a --- /dev/null +++ b/lib/gitlab/sherlock/location.rb @@ -0,0 +1,22 @@ +module Gitlab + module Sherlock + class Location + attr_reader :path, :line + + SHERLOCK_DIR = File.dirname(__FILE__) + + def self.from_ruby_location(location) + new(location.path, location.lineno) + end + + def initialize(path, line) + @path = path + @line = line + end + + def application? + @path.start_with?(Rails.root.to_s) && !path.start_with?(SHERLOCK_DIR) + end + end + end +end diff --git a/lib/gitlab/sherlock/middleware.rb b/lib/gitlab/sherlock/middleware.rb new file mode 100644 index 00000000000..fca7be858eb --- /dev/null +++ b/lib/gitlab/sherlock/middleware.rb @@ -0,0 +1,36 @@ +module Gitlab + module Sherlock + # Rack middleware used for tracking request metrics. + class Middleware + CONTENT_TYPES = /text\/html|application\/json/i + + IGNORE_PATHS = %r{^/sherlock} + + def initialize(app) + @app = app + end + + def call(env) + if instrument?(env) + call_with_instrumentation(env) + else + @app.call(env) + end + end + + def call_with_instrumentation(env) + trans = Transaction.new(env['REQUEST_METHOD'], env['REQUEST_URI']) + retval = trans.run { @app.call(env) } + + Sherlock.collection.add(trans) + + retval + end + + def instrument?(env) + !!(env['HTTP_ACCEPT'] =~ CONTENT_TYPES && + env['REQUEST_URI'] !~ IGNORE_PATHS) + end + end + end +end diff --git a/lib/gitlab/sherlock/query.rb b/lib/gitlab/sherlock/query.rb new file mode 100644 index 00000000000..af76e6fd2bf --- /dev/null +++ b/lib/gitlab/sherlock/query.rb @@ -0,0 +1,96 @@ +module Gitlab + module Sherlock + class Query + attr_reader :id, :query, :started_at, :finished_at, :backtrace + + PREFIX_NEWLINE = / + \s+(FROM + |(LEFT|RIGHT)?INNER\s+JOIN + |(LEFT|RIGHT)?OUTER\s+JOIN + |WHERE + |AND + |GROUP\s+BY + |ORDER\s+BY + |LIMIT + |OFFSET)\s+ + /ix + + def self.new_with_bindings(query, bindings, started_at, finished_at) + bindings.each_with_index do |(column, value), index| + quoted_value = ActiveRecord::Base.connection.quote(value) + + query = query.gsub("$#{index + 1}", quoted_value) + end + + new(query, started_at, finished_at) + end + + def initialize(query, started_at, finished_at) + @id = SecureRandom.uuid + @query = query + @started_at = started_at + @finished_at = finished_at + @backtrace = caller_locations.map do |loc| + Location.from_ruby_location(loc) + end + + unless @query.end_with?(';') + @query += ';' + end + end + + def duration + @duration ||= (@finished_at - @started_at) * 1000.0 + end + + def to_param + @id + end + + def formatted_query + @formatted_query ||= format_sql(@query) + end + + def last_application_frame + @last_application_frame ||= @backtrace.find(&:application?) + end + + def application_backtrace + @application_backtrace ||= @backtrace.select(&:application?) + end + + def explain + unless @explain + ActiveRecord::Base.connection.transaction do + @explain = raw_explain(@query).values.flatten.join("\n") + + # Roll back any queries that mutate data so we don't mess up + # anything when running explain on an INSERT, UPDATE, DELETE, etc. + raise ActiveRecord::Rollback + end + end + + @explain + end + + private + + def raw_explain(query) + if Gitlab::Database.postgresql? + explain = "EXPLAIN ANALYZE #{query};" + else + explain = "EXPLAIN #{query};" + end + + ActiveRecord::Base.connection.execute(explain) + end + + def format_sql(query) + query.each_line. + map { |line| line.strip }. + join("\n"). + gsub(PREFIX_NEWLINE) { "\n#{$1} " } + end + end + end +end diff --git a/lib/gitlab/sherlock/transaction.rb b/lib/gitlab/sherlock/transaction.rb new file mode 100644 index 00000000000..5cb3e86aa4e --- /dev/null +++ b/lib/gitlab/sherlock/transaction.rb @@ -0,0 +1,85 @@ +module Gitlab + module Sherlock + class Transaction + attr_reader :id, :type, :path, :queries, :file_samples, :started_at, + :finished_at + + def initialize(type, path) + @id = SecureRandom.uuid + @type = type + @path = path + @duration = 0 + @queries = [] + @file_samples = [] + @started_at = nil + @finished_at = nil + @thread = Thread.current + end + + def run + @started_at = Time.now + + subscriber = subscribe_to_active_record + + retval = profile_lines { yield } + + @finished_at = Time.now + + ActiveSupport::Notifications.unsubscribe(subscriber) + + retval + end + + def duration + @started_at && @finished_at ? @finished_at - @started_at : 0 + end + + def to_param + @id + end + + def sorted_queries + @queries.sort { |a, b| b.duration <=> a.duration } + end + + def sorted_file_samples + @file_samples.sort { |a, b| b.duration <=> a.duration } + end + + def find_query(id) + @queries.find { |query| query.id == id } + end + + def find_file_sample(id) + @file_samples.find { |sample| sample.id == id } + end + + def track_query(query, bindings, start, finish) + @queries << Query.new_with_bindings(query, bindings, start, finish) + end + + def profile_lines + retval = nil + + if Sherlock.enable_line_profiler? + retval, @file_samples = LineProfiler.new.profile { yield } + else + retval = yield + end + + retval + end + + def subscribe_to_active_record + ActiveSupport::Notifications.subscribe('sql.active_record') do |_, start, finish, _, data| + # In case somebody uses a multi-threaded server locally (e.g. Puma) we + # _only_ want to track queries that originate from the transaction + # thread. + next unless Thread.current == @thread + + track_query(data[:sql].strip, data[:binds], start, finish) + end + end + end + end +end |