Module: Gitlab::Profiler

Defined in:
lib/gitlab/profiler.rb

Constant Summary collapse

FILTERED_STRING = 
'[FILTERED]'
IGNORE_BACKTRACES = 
%w[
  lib/gitlab/i18n.rb
  lib/gitlab/request_context.rb
  config/initializers
  lib/gitlab/database/load_balancing/
  lib/gitlab/etag_caching/
  lib/gitlab/metrics/
  lib/gitlab/middleware/
  ee/lib/gitlab/middleware/
  lib/gitlab/performance_bar/
  lib/gitlab/query_limiting/
  lib/gitlab/tracing/
  lib/gitlab/profiler.rb
  lib/gitlab/correlation_id.rb
  lib/gitlab/webpack/dev_server_middleware.rb
  lib/gitlab/sidekiq_status/
  lib/gitlab/sidekiq_logging/
  lib/gitlab/sidekiq_middleware/
].freeze

Class Method Summary collapse

Class Method Details

.create_custom_logger(logger, private_token: nil) ⇒ Object 



90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
 
# File 'lib/gitlab/profiler.rb', line 90

def self.create_custom_logger(logger, private_token: nil)
  return unless logger

  logger.dup.tap do |new_logger|
    new_logger.instance_variable_set(:@private_token, private_token)

    class << new_logger
      attr_reader :load_times_by_model, :private_token

      def debug(message, *)
        message = message.gsub(private_token, FILTERED_STRING) if private_token

        _, type, time = *message.match(/(\w+) Load \(([0-9.]+)ms\)/)

        if type && time
          @load_times_by_model ||= {}
          @load_times_by_model[type] ||= []
          @load_times_by_model[type] << time.to_f
        end

        super

        Gitlab::BacktraceCleaner.clean_backtrace(caller).each do |caller_line|
          stripped_caller_line = caller_line.sub("#{Rails.root}/", '')

          super("  ↳ #{stripped_caller_line}")
        end
      end
    end
  end
end

.log_load_times_by_model(logger) ⇒ Object

rubocop: disable CodeReuse/ActiveRecord



159
160
161
162
163
164
165
166
167
168
169
 
# File 'lib/gitlab/profiler.rb', line 159

def self.log_load_times_by_model(logger)
  return unless logger.respond_to?(:load_times_by_model)

  summarised_load_times = logger.load_times_by_model.to_a.map do |(model, times)|
    [model, times.count, times.sum]
  end

  summarised_load_times.sort_by(&:last).reverse_each do |(model, query_count, time)|
    logger.info("#{model} total (#{query_count}): #{time.round(2)}ms")
  end
end

.profile(url, logger: nil, post_data: nil, user: nil, private_token: nil, profiler_options: {}) ⇒ Object

Takes a URL to profile (can be a fully-qualified URL, or an absolute path) and returns the profiler result. Formatting that result is the caller’s responsibility. Requests are GET requests unless post_data is passed.

Optional arguments:

  • logger: will be used for SQL logging, including a summary at the end of the log file of the total time spent per model class.

  • post_data: a string of raw POST data to use. Changes the HTTP verb to POST.

  • user: a user to authenticate as.

  • private_token: instead of providing a user instance, the token can be given as a string. Takes precedence over the user option.

  • profiler_options: A keyword Hash of arguments passed to the profiler. Defaults: { mode: :wall, out: <some temporary file>, interval: 1000, raw: true }



46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
 
# File 'lib/gitlab/profiler.rb', line 46

def self.profile(url, logger: nil, post_data: nil, user: nil, private_token: nil, profiler_options: {})
  app = ActionDispatch::Integration::Session.new(Rails.application)
  verb = :get
  headers = {}

  if post_data
    verb = :post
    headers['Content-Type'] = 'application/json'
  end

  if private_token
    headers['Private-Token'] = private_token
    user = nil # private_token overrides user
  end

  logger = create_custom_logger(logger, private_token: private_token)

  result = ::Gitlab::SafeRequestStore.ensure_request_store do
    # Make an initial call for an asset path in development mode to avoid
    # sprockets dominating the profiler output.
    ActionController::Base.helpers.asset_path('katex.css') if Rails.env.development?

    # Rails loads internationalization files lazily the first time a
    # translation is needed. Running this prevents this overhead from showing
    # up in profiles.
    ::I18n.t('.')[:test_string]

    # Remove API route mounting from the profile.
    app.get('/api/v4/users')

    with_custom_logger(logger) do
      with_user(user) do
        with_profiler(profiler_options) do
          app.public_send(verb, url, params: post_data, headers: headers) # rubocop:disable GitlabSecurity/PublicSend
        end
      end
    end
  end

  log_load_times_by_model(logger)

  result
end

.remove_method(klass, meth) ⇒ Object 



154
155
156
 
# File 'lib/gitlab/profiler.rb', line 154

def self.remove_method(klass, meth)
  klass.send(:remove_method, meth) if klass.instance_methods(false).include?(meth) # rubocop:disable GitlabSecurity/PublicSend
end

.with_custom_logger(logger) ⇒ Object 



122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
 
# File 'lib/gitlab/profiler.rb', line 122

def self.with_custom_logger(logger)
  original_colorize_logging = ActiveSupport::LogSubscriber.colorize_logging
  original_activerecord_logger = ActiveRecord::Base.logger
  original_actioncontroller_logger = ActionController::Base.logger

  if logger
    ActiveSupport::LogSubscriber.colorize_logging = false
    ActiveRecord::Base.logger = logger
    ActionController::Base.logger = logger
  end

  yield.tap do
    ActiveSupport::LogSubscriber.colorize_logging = original_colorize_logging
    ActiveRecord::Base.logger = original_activerecord_logger
    ActionController::Base.logger = original_actioncontroller_logger
  end
end

.with_profiler(profiler_options) ⇒ Object

rubocop: enable CodeReuse/ActiveRecord



172
173
174
175
176
177
 
# File 'lib/gitlab/profiler.rb', line 172

def self.with_profiler(profiler_options)
  require 'stackprof'
  args = { mode: :wall, interval: 1000, raw: true }.merge!(profiler_options)
  args[:out] ||= ::Tempfile.new(["profile-#{Time.now.to_i}-", ".dump"]).path
  ::StackProf.run(**args) { yield }
end

.with_user(user) ⇒ Object 



140
141
142
143
144
145
146
147
148
149
150
151
152
 
# File 'lib/gitlab/profiler.rb', line 140

def self.with_user(user)
  if user
    API::Helpers::CommonHelpers.send(:define_method, :find_current_user!) { user } # rubocop:disable GitlabSecurity/PublicSend
    ApplicationController.send(:define_method, :current_user) { user } # rubocop:disable GitlabSecurity/PublicSend
    ApplicationController.send(:define_method, :authenticate_user!) {} # rubocop:disable GitlabSecurity/PublicSend
  end

  yield.tap do
    remove_method(API::Helpers::CommonHelpers, :find_current_user!)
    remove_method(ApplicationController, :current_user)
    remove_method(ApplicationController, :authenticate_user!)
  end
end