gitaly_client.rb 15.6 KB
Newer Older
1
2
require 'base64'

3
require 'gitaly'
4
5
require 'grpc/health/v1/health_pb'
require 'grpc/health/v1/health_services_pb'
6
7
8

module Gitlab
  module GitalyClient
Pawel Chojnacki's avatar
Pawel Chojnacki committed
9
    include Gitlab::Metrics::Methods
10
11
12
13
14
15
    module MigrationStatus
      DISABLED = 1
      OPT_IN = 2
      OPT_OUT = 3
    end

16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
    class TooManyInvocationsError < StandardError
      attr_reader :call_site, :invocation_count, :max_call_stack

      def initialize(call_site, invocation_count, max_call_stack, most_invoked_stack)
        @call_site = call_site
        @invocation_count = invocation_count
        @max_call_stack = max_call_stack
        stacks = most_invoked_stack.join('\n') if most_invoked_stack

        msg = "GitalyClient##{call_site} called #{invocation_count} times from single request. Potential n+1?"
        msg << "\nThe following call site called into Gitaly #{max_call_stack} times:\n#{stacks}\n" if stacks

        super(msg)
      end
    end

32
    SERVER_VERSION_FILE = 'GITALY_SERVER_VERSION'.freeze
33
    MAXIMUM_GITALY_CALLS = 35
34
    CLIENT_NAME = (Sidekiq.server? ? 'gitlab-sidekiq' : 'gitlab-web').freeze
35

Jacob Vosmaer's avatar
Jacob Vosmaer committed
36
    MUTEX = Mutex.new
37

38
    class << self
39
      attr_accessor :query_time
40
41
42
    end

    self.query_time = 0
43

44
45
46
    define_histogram :gitaly_migrate_call_duration_seconds do
      docstring "Gitaly migration call execution timings"
      base_labels gitaly_enabled: nil, feature: nil
47
48
    end

49
50
51
    define_histogram :gitaly_controller_action_duration_seconds do
      docstring "Gitaly endpoint histogram by controller and action combination"
      base_labels Gitlab::Metrics::Transaction::BASE_LABELS.merge(gitaly_service: nil, rpc: nil)
52
    end
53

Jacob Vosmaer's avatar
Jacob Vosmaer committed
54
55
56
57
58
    def self.stub(name, storage)
      MUTEX.synchronize do
        @stubs ||= {}
        @stubs[storage] ||= {}
        @stubs[storage][name] ||= begin
59
60
          klass = stub_class(name)
          addr = stub_address(storage)
Jacob Vosmaer's avatar
Jacob Vosmaer committed
61
          klass.new(addr, :this_channel_is_insecure)
62
63
        end
      end
64
65
    end

66
67
68
69
70
71
72
73
74
75
76
77
78
79
    def self.stub_class(name)
      if name == :health_check
        Grpc::Health::V1::Health::Stub
      else
        Gitaly.const_get(name.to_s.camelcase.to_sym).const_get(:Stub)
      end
    end

    def self.stub_address(storage)
      addr = address(storage)
      addr = addr.sub(%r{^tcp://}, '') if URI(addr).scheme == 'tcp'
      addr
    end

Jacob Vosmaer's avatar
Jacob Vosmaer committed
80
81
82
83
    def self.clear_stubs!
      MUTEX.synchronize do
        @stubs = nil
      end
84
85
    end

86
87
88
89
    def self.random_storage
      Gitlab.config.repositories.storages.keys.sample
    end

Jacob Vosmaer's avatar
Jacob Vosmaer committed
90
91
92
    def self.address(storage)
      params = Gitlab.config.repositories.storages[storage]
      raise "storage not found: #{storage.inspect}" if params.nil?
93

Jacob Vosmaer's avatar
Jacob Vosmaer committed
94
95
96
97
      address = params['gitaly_address']
      unless address.present?
        raise "storage #{storage.inspect} is missing a gitaly_address"
      end
98

Jacob Vosmaer's avatar
Jacob Vosmaer committed
99
100
      unless URI(address).scheme.in?(%w(tcp unix))
        raise "Unsupported Gitaly address: #{address.inspect} does not use URL scheme 'tcp' or 'unix'"
101
102
      end

Jacob Vosmaer's avatar
Jacob Vosmaer committed
103
      address
104
105
    end

106
107
108
109
    def self.address_metadata(storage)
      Base64.strict_encode64(JSON.dump({ storage => { 'address' => address(storage), 'token' => token(storage) } }))
    end

Jacob Vosmaer's avatar
Jacob Vosmaer committed
110
111
    # All Gitaly RPC call sites should use GitalyClient.call. This method
    # makes sure that per-request authentication headers are set.
112
113
114
115
116
117
118
119
120
121
122
123
    #
    # This method optionally takes a block which receives the keyword
    # arguments hash 'kwargs' that will be passed to gRPC. This allows the
    # caller to modify or augment the keyword arguments. The block must
    # return a hash.
    #
    # For example:
    #
    # GitalyClient.call(storage, service, rpc, request) do |kwargs|
    #   kwargs.merge(deadline: Time.now + 10)
    # end
    #
124
    def self.call(storage, service, rpc, request, remote_storage: nil, timeout: nil)
125
      start = Gitlab::Metrics::System.monotonic_time
126
127
      request_hash = request.is_a?(Google::Protobuf::MessageExts) ? request.to_h : {}
      @current_call_id ||= SecureRandom.uuid
128

129
130
      enforce_gitaly_request_limits(:call)

131
      kwargs = request_kwargs(storage, timeout, remote_storage: remote_storage)
132
      kwargs = yield(kwargs) if block_given?
133

134
      stub(service, storage).__send__(rpc, request, kwargs) # rubocop:disable GitlabSecurity/PublicSend
135
136
    rescue GRPC::Unavailable => ex
      handle_grpc_unavailable!(ex)
137
    ensure
138
139
140
141
      duration = Gitlab::Metrics::System.monotonic_time - start

      # Keep track, seperately, for the performance bar
      self.query_time += duration
142
      gitaly_controller_action_duration_seconds.observe(
143
144
        current_transaction_labels.merge(gitaly_service: service.to_s, rpc: rpc.to_s),
        duration)
145
146
147
148

      add_call_details(id: @current_call_id, feature: service, duration: duration, request: request_hash)

      @current_call_id = nil
149
150
    end

151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
    def self.handle_grpc_unavailable!(ex)
      status = ex.to_status
      raise ex unless status.details == 'Endpoint read failed'

      # There is a bug in grpc 1.8.x that causes a client process to get stuck
      # always raising '14:Endpoint read failed'. The only thing that we can
      # do to recover is to restart the process.
      #
      # See https://gitlab.com/gitlab-org/gitaly/issues/1029

      if Sidekiq.server?
        raise Gitlab::SidekiqMiddleware::Shutdown::WantShutdown.new(ex.to_s)
      else
        # SIGQUIT requests a Unicorn worker to shut down gracefully after the current request.
        Process.kill('QUIT', Process.pid)
      end

      raise ex
    end
    private_class_method :handle_grpc_unavailable!

172
173
    def self.current_transaction_labels
      Gitlab::Metrics::Transaction.current&.labels || {}
174
    end
175
    private_class_method :current_transaction_labels
176

177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
    # For some time related tasks we can't rely on `Time.now` since it will be
    # affected by Timecop in some tests, and the clock of some gitaly-related
    # components (grpc's c-core and gitaly server) use system time instead of
    # timecop's time, so tests will fail.
    # `Time.at(Process.clock_gettime(Process::CLOCK_REALTIME))` will circumvent
    # timecop.
    def self.real_time
      Time.at(Process.clock_gettime(Process::CLOCK_REALTIME))
    end
    private_class_method :real_time

    def self.authorization_token(storage)
      token = token(storage).to_s
      issued_at = real_time.to_i.to_s
      hmac = OpenSSL::HMAC.hexdigest(OpenSSL::Digest::SHA256.new, token, issued_at)

      "v2.#{hmac}.#{issued_at}"
    end
    private_class_method :authorization_token

197
    def self.request_kwargs(storage, timeout, remote_storage: nil)
198
      metadata = {
199
        'authorization' => "Bearer #{authorization_token(storage)}",
200
201
202
203
204
205
        'client_name' => CLIENT_NAME
      }

      feature_stack = Thread.current[:gitaly_feature_stack]
      feature = feature_stack && feature_stack[0]
      metadata['call_site'] = feature.to_s if feature
206
      metadata['gitaly-servers'] = address_metadata(remote_storage) if remote_storage
207

Jacob Vosmaer's avatar
Jacob Vosmaer committed
208
      metadata.merge!(server_feature_flags)
209

210
211
212
213
214
215
216
      result = { metadata: metadata }

      # nil timeout indicates that we should use the default
      timeout = default_timeout if timeout.nil?

      return result unless timeout > 0

217
      deadline = real_time + timeout
218
219
220
      result[:deadline] = deadline

      result
221
222
    end

223
    SERVER_FEATURE_FLAGS = %w[gogit_findcommit].freeze
224

Jacob Vosmaer's avatar
Jacob Vosmaer committed
225
226
227
228
    def self.server_feature_flags
      SERVER_FEATURE_FLAGS.map do |f|
        ["gitaly-feature-#{f.tr('_', '-')}", feature_enabled?(f).to_s]
      end.to_h
229
230
    end

231
232
233
234
235
236
237
    def self.token(storage)
      params = Gitlab.config.repositories.storages[storage]
      raise "storage not found: #{storage.inspect}" if params.nil?

      params['gitaly_token'].presence || Gitlab.config.gitaly['token']
    end

238
239
240
    # Evaluates whether a feature toggle is on or off
    def self.feature_enabled?(feature_name, status: MigrationStatus::OPT_IN)
      # Disabled features are always off!
241
      return false if status == MigrationStatus::DISABLED
242

243
      feature = Feature.get("gitaly_#{feature_name}")
244

245
246
247
248
249
250
251
252
253
      # If the feature has been set, always evaluate
      if Feature.persisted?(feature)
        if feature.percentage_of_time_value > 0
          # Probabilistically enable this feature
          return Random.rand() * 100 < feature.percentage_of_time_value
        end

        return feature.enabled?
      end
254

255
256
257
258
259
260
      # If the feature has not been set, the default depends
      # on it's status
      case status
      when MigrationStatus::OPT_OUT
        true
      when MigrationStatus::OPT_IN
261
        opt_into_all_features? && !explicit_opt_in_required.include?(feature_name)
262
263
      else
        false
264
      end
265
266
267
268
    rescue => ex
      # During application startup feature lookups in SQL can fail
      Rails.logger.warn "exception while checking Gitaly feature status for #{feature_name}: #{ex}"
      false
269
    end
270

271
272
273
274
275
276
277
    # We have a mechanism to let GitLab automatically opt in to all Gitaly
    # features. We want to be able to exclude some features from automatic
    # opt-in. This function has an override in EE.
    def self.explicit_opt_in_required
      []
    end

278
279
280
281
    # opt_into_all_features? returns true when the current environment
    # is one in which we opt into features automatically
    def self.opt_into_all_features?
      Rails.env.development? || ENV["GITALY_FEATURE_DEFAULT_ON"] == "1"
282
    end
283
    private_class_method :opt_into_all_features?
284

285
    def self.migrate(feature, status: MigrationStatus::OPT_IN)
286
287
288
289
      # Enforce limits at both the `migrate` and `call` sites to ensure that
      # problems are not hidden by a feature being disabled
      enforce_gitaly_request_limits(:migrate)

290
      is_enabled  = feature_enabled?(feature, status: status)
291
292
293
294
      metric_name = feature.to_s
      metric_name += "_gitaly" if is_enabled

      Gitlab::Metrics.measure(metric_name) do
295
296
        # Some migrate calls wrap other migrate calls
        allow_n_plus_1_calls do
297
298
299
          feature_stack = Thread.current[:gitaly_feature_stack] ||= []
          feature_stack.unshift(feature)
          begin
300
            start = Gitlab::Metrics::System.monotonic_time
301
302
            @current_call_id = SecureRandom.uuid
            call_details = { id: @current_call_id }
303
304
            yield is_enabled
          ensure
305
            total_time = Gitlab::Metrics::System.monotonic_time - start
306
            gitaly_migrate_call_duration_seconds.observe({ gitaly_enabled: is_enabled, feature: feature }, total_time)
307
308
            feature_stack.shift
            Thread.current[:gitaly_feature_stack] = nil if feature_stack.empty?
309
310

            add_call_details(call_details.merge(feature: feature, duration: total_time))
311
          end
312
313
314
315
316
317
318
        end
      end
    end

    # Ensures that Gitaly is not being abuse through n+1 misuse etc
    def self.enforce_gitaly_request_limits(call_site)
      # Only count limits in request-response environments (not sidekiq for example)
319
      return unless Gitlab::SafeRequestStore.active?
320
321
322
323
324

      # This is this actual number of times this call was made. Used for information purposes only
      actual_call_count = increment_call_count("gitaly_#{call_site}_actual")

      # Do no enforce limits in production
325
      return if Rails.env.production? || ENV["GITALY_DISABLE_REQUEST_LIMITS"]
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342

      # Check if this call is nested within a allow_n_plus_1_calls
      # block and skip check if it is
      return if get_call_count(:gitaly_call_count_exception_block_depth) > 0

      # This is the count of calls outside of a `allow_n_plus_1_calls` block
      # It is used for enforcement but not statistics
      permitted_call_count = increment_call_count("gitaly_#{call_site}_permitted")

      count_stack

      return if permitted_call_count <= MAXIMUM_GITALY_CALLS

      raise TooManyInvocationsError.new(call_site, actual_call_count, max_call_count, max_stacks)
    end

    def self.allow_n_plus_1_calls
343
      return yield unless Gitlab::SafeRequestStore.active?
344
345
346
347
348
349
350
351
352
353

      begin
        increment_call_count(:gitaly_call_count_exception_block_depth)
        yield
      ensure
        decrement_call_count(:gitaly_call_count_exception_block_depth)
      end
    end

    def self.get_call_count(key)
354
      Gitlab::SafeRequestStore[key] || 0
355
356
357
358
    end
    private_class_method :get_call_count

    def self.increment_call_count(key)
359
360
      Gitlab::SafeRequestStore[key] ||= 0
      Gitlab::SafeRequestStore[key] += 1
361
362
363
364
    end
    private_class_method :increment_call_count

    def self.decrement_call_count(key)
365
      Gitlab::SafeRequestStore[key] -= 1
366
367
368
369
370
371
    end
    private_class_method :decrement_call_count

    # Returns an estimate of the number of Gitaly calls made for this
    # request
    def self.get_request_count
372
      return 0 unless Gitlab::SafeRequestStore.active?
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388

      gitaly_migrate_count = get_call_count("gitaly_migrate_actual")
      gitaly_call_count = get_call_count("gitaly_call_actual")

      # Using the maximum of migrate and call_count will provide an
      # indicator of how many Gitaly calls will be made, even
      # before a feature is enabled. This provides us with a single
      # metric, but not an exact number, but this tradeoff is acceptable
      if gitaly_migrate_count > gitaly_call_count
        gitaly_migrate_count
      else
        gitaly_call_count
      end
    end

    def self.reset_counts
389
      return unless Gitlab::SafeRequestStore.active?
390
391

      %w[migrate call].each do |call_site|
392
393
        Gitlab::SafeRequestStore["gitaly_#{call_site}_actual"] = 0
        Gitlab::SafeRequestStore["gitaly_#{call_site}_permitted"] = 0
394
395
      end
    end
396

397
    def self.add_call_details(details)
398
399
      id = details.delete(:id)

400
      return unless id && Gitlab::SafeRequestStore[:peek_enabled]
401

402
403
404
      Gitlab::SafeRequestStore['gitaly_call_details'] ||= {}
      Gitlab::SafeRequestStore['gitaly_call_details'][id] ||= {}
      Gitlab::SafeRequestStore['gitaly_call_details'][id].merge!(details)
405
406
    end

407
    def self.list_call_details
408
      return {} unless Gitlab::SafeRequestStore[:peek_enabled]
409

410
      Gitlab::SafeRequestStore['gitaly_call_details'] || {}
411
412
    end

413
414
415
416
    def self.expected_server_version
      path = Rails.root.join(SERVER_VERSION_FILE)
      path.read.chomp
    end
417

418
419
    def self.timestamp(time)
      Google::Protobuf::Timestamp.new(seconds: time.to_i)
420
421
    end

422
423
    # The default timeout on all Gitaly calls
    def self.default_timeout
424
      return no_timeout if Sidekiq.server?
425
426
427
428
429
430
431
432
433
434
435
436

      timeout(:gitaly_timeout_default)
    end

    def self.fast_timeout
      timeout(:gitaly_timeout_fast)
    end

    def self.medium_timeout
      timeout(:gitaly_timeout_medium)
    end

437
438
439
440
    def self.no_timeout
      0
    end

441
442
443
444
445
    def self.timeout(timeout_name)
      Gitlab::CurrentSettings.current_application_settings[timeout_name]
    end
    private_class_method :timeout

446
447
    # Count a stack. Used for n+1 detection
    def self.count_stack
448
      return unless Gitlab::SafeRequestStore.active?
449

450
      stack_string = Gitlab::Profiler.clean_backtrace(caller).drop(1).join("\n")
451

452
      Gitlab::SafeRequestStore[:stack_counter] ||= Hash.new
453

454
455
      count = Gitlab::SafeRequestStore[:stack_counter][stack_string] || 0
      Gitlab::SafeRequestStore[:stack_counter][stack_string] = count + 1
456
457
458
459
460
    end
    private_class_method :count_stack

    # Returns a count for the stack which called Gitaly the most times. Used for n+1 detection
    def self.max_call_count
461
      return 0 unless Gitlab::SafeRequestStore.active?
462

463
      stack_counter = Gitlab::SafeRequestStore[:stack_counter]
464
465
466
467
468
469
470
471
      return 0 unless stack_counter

      stack_counter.values.max
    end
    private_class_method :max_call_count

    # Returns the stacks that calls Gitaly the most times. Used for n+1 detection
    def self.max_stacks
472
      return nil unless Gitlab::SafeRequestStore.active?
473

474
      stack_counter = Gitlab::SafeRequestStore[:stack_counter]
475
476
477
478
479
480
481
482
      return nil unless stack_counter

      max = max_call_count
      return nil if max.zero?

      stack_counter.select { |_, v| v == max }.keys
    end
    private_class_method :max_stacks
483
484
  end
end