diff --git a/config/initializers/7_gitlab_http.rb b/config/initializers/7_gitlab_http.rb
index 7aca9a4fe5c5fd526c87c0ee78766e84cccac7d4..567f0b726dbbd013f46b6d6038a1d554db39a3ba 100644
--- a/config/initializers/7_gitlab_http.rb
+++ b/config/initializers/7_gitlab_http.rb
@@ -22,6 +22,9 @@
config.silent_mode_log_info_proc = ->(message, http_method) do
Gitlab::SilentMode.log_info(message: message, outbound_http_request_method: http_method)
end
+ config.log_with_level_proc = ->(log_level, message_params) do
+ Gitlab::AppJsonLogger.public_send(log_level, message_params)
+ end
end
if Gitlab.config.gitlab['http_client'].present?
diff --git a/gems/gitlab-http/lib/gitlab/http_v2/client.rb b/gems/gitlab-http/lib/gitlab/http_v2/client.rb
index 147517de7061f5bdfa89a487eac4550306115e2a..de594bd0b31413dfbf87b3999b5865b58cf13390 100644
--- a/gems/gitlab-http/lib/gitlab/http_v2/client.rb
+++ b/gems/gitlab-http/lib/gitlab/http_v2/client.rb
@@ -72,15 +72,23 @@ def perform_request(http_method, path, options, &block)
def async_perform_request(http_method, path, options, options_with_timeouts, log_info, &block)
start_time = nil
read_total_timeout = options.fetch(:timeout, DEFAULT_READ_TOTAL_TIMEOUT)
+ byte_size = 0
+ already_logged = false
promise = Concurrent::Promise.new do
Gitlab::Utils.restrict_within_concurrent_ruby do
httparty_perform_request(http_method, path, options_with_timeouts) do |fragment|
start_time ||= system_monotonic_time
elapsed = system_monotonic_time - start_time
+ byte_size += fragment.bytesize if should_log_response_size?
raise ReadTotalTimeout, "Request timed out after #{elapsed} seconds" if elapsed > read_total_timeout
+ if should_log_response_size? && byte_size > expected_max_response_size && !already_logged
+ configuration.log_with_level(:debug, message: 'gitlab/http: response size', size: byte_size)
+ already_logged = true
+ end
+
yield fragment if block
end
end
@@ -92,10 +100,18 @@ def async_perform_request(http_method, path, options, options_with_timeouts, log
def sync_perform_request(http_method, path, options, options_with_timeouts, log_info, &block)
start_time = nil
read_total_timeout = options.fetch(:timeout, DEFAULT_READ_TOTAL_TIMEOUT)
+ byte_size = 0
+ already_logged = false
httparty_perform_request(http_method, path, options_with_timeouts) do |fragment|
start_time ||= system_monotonic_time
elapsed = system_monotonic_time - start_time
+ byte_size += fragment.bytesize if should_log_response_size?
+
+ if should_log_response_size? && byte_size > expected_max_response_size && !already_logged
+ configuration.log_with_level(:debug, message: 'gitlab/http: response size', size: byte_size)
+ already_logged = true
+ end
raise ReadTotalTimeout, "Request timed out after #{elapsed} seconds" if elapsed > read_total_timeout
@@ -128,6 +144,16 @@ def raise_if_blocked_by_silent_mode(http_method)
def system_monotonic_time
Process.clock_gettime(Process::CLOCK_MONOTONIC, :float_second)
end
+
+ def should_log_response_size?
+ return @should_log_response_size if instance_variable_defined?(:@should_log_response_size)
+
+ @should_log_response_size = ENV["GITLAB_LOG_DECOMPRESSED_RESPONSE_BYTESIZE"].to_i.positive?
+ end
+
+ def expected_max_response_size
+ ENV["GITLAB_LOG_DECOMPRESSED_RESPONSE_BYTESIZE"].to_i
+ end
end
end
end
diff --git a/gems/gitlab-http/lib/gitlab/http_v2/configuration.rb b/gems/gitlab-http/lib/gitlab/http_v2/configuration.rb
index 98b07d0cf27bf2cd73d60a290ec8283ead82d013..0f62eea0774beffb46708a051a744cc5f9f18ae9 100644
--- a/gems/gitlab-http/lib/gitlab/http_v2/configuration.rb
+++ b/gems/gitlab-http/lib/gitlab/http_v2/configuration.rb
@@ -3,7 +3,7 @@
module Gitlab
module HTTP_V2
class Configuration
- attr_accessor :allowed_internal_uris, :log_exception_proc, :silent_mode_log_info_proc
+ attr_accessor :allowed_internal_uris, :log_exception_proc, :silent_mode_log_info_proc, :log_with_level_proc
def log_exception(...)
log_exception_proc&.call(...)
@@ -12,6 +12,10 @@ def log_exception(...)
def silent_mode_log_info(...)
silent_mode_log_info_proc&.call(...)
end
+
+ def log_with_level(...)
+ log_with_level_proc&.call(...)
+ end
end
end
end
diff --git a/gems/gitlab-http/spec/gitlab/http_v2_spec.rb b/gems/gitlab-http/spec/gitlab/http_v2_spec.rb
index 3151761d375fe085ea3ab91999f21ada1a0a996c..74460c8728969fcdec608d83e41caad1b50a940d 100644
--- a/gems/gitlab-http/spec/gitlab/http_v2_spec.rb
+++ b/gems/gitlab-http/spec/gitlab/http_v2_spec.rb
@@ -246,6 +246,71 @@ def read_body(*)
end
end
+ describe 'logging response size' do
+ context 'when GITLAB_LOG_DECOMPRESSED_RESPONSE_BYTESIZE is not set' do
+ before do
+ stub_full_request('http://example.org', method: :any).to_return(status: 200, body: 'hello world')
+ end
+
+ it 'does not log response size' do
+ expect(described_class.configuration)
+ .not_to receive(:log_with_level)
+
+ described_class.get('http://example.org')
+ end
+
+ context 'when the request is async' do
+ it 'does not log response size' do
+ expect(described_class.configuration)
+ .not_to receive(:log_with_level)
+
+ described_class.get('http://example.org', async: true).execute.value
+ end
+ end
+ end
+
+ context 'when GITLAB_LOG_DECOMPRESSED_RESPONSE_BYTESIZE is set' do
+ before do
+ described_class::Client.remove_instance_variable(:@should_log_response_size)
+ stub_env('GITLAB_LOG_DECOMPRESSED_RESPONSE_BYTESIZE', 5)
+ stub_full_request('http://example.org', method: :any).to_return(status: 200, body: 'hello world')
+ end
+
+ it 'logs the response size' do
+ expect(described_class.configuration)
+ .to receive(:log_with_level)
+ .with(:debug, { message: "gitlab/http: response size", size: 11 })
+ .once
+
+ described_class.get('http://example.org')
+ end
+
+ context 'when the request is async' do
+ it 'logs response size' do
+ expect(described_class.configuration)
+ .to receive(:log_with_level)
+ .with(:debug, { message: "gitlab/http: response size", size: 11 })
+ .once
+
+ described_class.get('http://example.org', async: true).execute.value
+ end
+ end
+
+ context 'and the response size is smaller than the limit' do
+ before do
+ stub_env('GITLAB_LOG_DECOMPRESSED_RESPONSE_BYTESIZE', 50)
+ end
+
+ it 'does not log the response size' do
+ expect(described_class.configuration)
+ .not_to receive(:log_with_level)
+
+ described_class.get('http://example.org')
+ end
+ end
+ end
+ end
+
describe '.try_get' do
let(:path) { 'http://example.org' }
let(:default_timeout_options) { described_class::Client::DEFAULT_TIMEOUT_OPTIONS }
diff --git a/gems/gitlab-http/spec/spec_helper.rb b/gems/gitlab-http/spec/spec_helper.rb
index c2f10eb22cc86efd810fc51435a8d49d873848c3..c5435e0b8d6834f0bafe4ab506e6ffffc3e5df5d 100644
--- a/gems/gitlab-http/spec/spec_helper.rb
+++ b/gems/gitlab-http/spec/spec_helper.rb
@@ -8,6 +8,7 @@
require 'gitlab/http_v2'
require 'gitlab/http_v2/configuration'
require 'gitlab/stub_requests'
+
require 'webmock/rspec'
RSpec.configure do |config|
@@ -46,4 +47,8 @@
config.silent_mode_log_info_proc = ->(message, http_method) do
# no-op
end
+
+ config.log_with_level_proc = ->(log_level, message_params) do
+ # no-op
+ end
end
diff --git a/keeps/quarantine_flaky_tests.rb b/keeps/quarantine_flaky_tests.rb
index a12e59219dd5bf325323ec22120589fc488bbc92..a6a0aa20f6d97c44cea1dc0ff47fc46d4c80f6ab 100644
--- a/keeps/quarantine_flaky_tests.rb
+++ b/keeps/quarantine_flaky_tests.rb
@@ -14,6 +14,10 @@
p message
p http_method
end
+ config.log_with_level_proc = ->(log_level, message_params) do
+ p log_level
+ p message_params
+ end
end
module Keeps
diff --git a/spec/initializers/gitlab_http_spec.rb b/spec/initializers/gitlab_http_spec.rb
index e901ce18229ec64d993be99f01fe06db1feb3ad6..91d9b445719a22a7a83199f39cabd99274c46fa2 100644
--- a/spec/initializers/gitlab_http_spec.rb
+++ b/spec/initializers/gitlab_http_spec.rb
@@ -17,6 +17,14 @@ def load_initializer
expect { described_class.get('http://example.org') }.to raise_error(Net::ReadTimeout)
end
+ describe 'log_with_level_proc' do
+ it 'calls AppJsonLogger with the correct log level and parameters' do
+ expect(::Gitlab::AppJsonLogger).to receive(:debug).with({ message: 'Test' })
+
+ described_class.configuration.log_with_level(:debug, message: 'Test')
+ end
+ end
+
context 'when silent_mode_enabled is true' do
before do
stub_application_setting(silent_mode_enabled: true)