2021-08-13 03:10:09 +00:00
|
|
|
# frozen_string_literal: true
|
|
|
|
|
|
|
|
module Gitlab
|
|
|
|
module Database
|
|
|
|
module Transaction
|
|
|
|
class Context
|
|
|
|
attr_reader :context
|
|
|
|
|
2022-03-15 12:07:44 +00:00
|
|
|
LOG_SAVEPOINTS_THRESHOLD = 1 # 1 `SAVEPOINT` created in a transaction
|
|
|
|
LOG_DURATION_S_THRESHOLD = 120 # transaction that is running for 2 minutes or longer
|
|
|
|
LOG_EXTERNAL_HTTP_COUNT_THRESHOLD = 50 # 50 external HTTP requests executed within transaction
|
|
|
|
LOG_EXTERNAL_HTTP_DURATION_S_THRESHOLD = 1 # 1 second spent in HTTP requests in total within transaction
|
2021-08-13 03:10:09 +00:00
|
|
|
LOG_THROTTLE_DURATION = 1
|
|
|
|
|
|
|
|
def initialize
|
|
|
|
@context = {}
|
|
|
|
end
|
|
|
|
|
|
|
|
def set_start_time
|
|
|
|
@context[:start_time] = current_timestamp
|
|
|
|
end
|
|
|
|
|
2021-08-25 09:10:52 +00:00
|
|
|
def set_depth(depth)
|
|
|
|
@context[:depth] = [@context[:depth].to_i, depth].max
|
|
|
|
end
|
|
|
|
|
2021-08-13 03:10:09 +00:00
|
|
|
def increment_savepoints
|
|
|
|
@context[:savepoints] = @context[:savepoints].to_i + 1
|
|
|
|
end
|
|
|
|
|
|
|
|
def increment_rollbacks
|
|
|
|
@context[:rollbacks] = @context[:rollbacks].to_i + 1
|
|
|
|
end
|
|
|
|
|
|
|
|
def increment_releases
|
|
|
|
@context[:releases] = @context[:releases].to_i + 1
|
|
|
|
end
|
|
|
|
|
|
|
|
def track_sql(sql)
|
|
|
|
(@context[:queries] ||= []).push(sql)
|
|
|
|
end
|
|
|
|
|
2021-08-26 09:11:15 +00:00
|
|
|
def track_backtrace(backtrace)
|
|
|
|
cleaned_backtrace = Gitlab::BacktraceCleaner.clean_backtrace(backtrace)
|
|
|
|
(@context[:backtraces] ||= []).push(cleaned_backtrace)
|
|
|
|
end
|
|
|
|
|
2022-03-15 12:07:44 +00:00
|
|
|
def initialize_external_http_tracking
|
|
|
|
@context[:external_http_count_start] = external_http_requests_count_total
|
|
|
|
@context[:external_http_duration_start] = external_http_requests_duration_total
|
|
|
|
end
|
|
|
|
|
2021-08-13 03:10:09 +00:00
|
|
|
def duration
|
|
|
|
return unless @context[:start_time].present?
|
|
|
|
|
|
|
|
current_timestamp - @context[:start_time]
|
|
|
|
end
|
|
|
|
|
|
|
|
def savepoints_threshold_exceeded?
|
2021-08-24 00:11:18 +00:00
|
|
|
@context[:savepoints].to_i >= LOG_SAVEPOINTS_THRESHOLD
|
2021-08-13 03:10:09 +00:00
|
|
|
end
|
|
|
|
|
|
|
|
def duration_threshold_exceeded?
|
2021-08-24 00:11:18 +00:00
|
|
|
duration.to_i >= LOG_DURATION_S_THRESHOLD
|
2021-08-13 03:10:09 +00:00
|
|
|
end
|
|
|
|
|
2022-03-15 12:07:44 +00:00
|
|
|
def external_http_requests_threshold_exceeded?
|
|
|
|
external_http_requests_count >= LOG_EXTERNAL_HTTP_COUNT_THRESHOLD ||
|
|
|
|
external_http_requests_duration >= LOG_EXTERNAL_HTTP_DURATION_S_THRESHOLD
|
|
|
|
end
|
|
|
|
|
2021-08-13 03:10:09 +00:00
|
|
|
def should_log?
|
2021-08-25 09:10:52 +00:00
|
|
|
return false if logged_already?
|
|
|
|
|
2022-03-15 12:07:44 +00:00
|
|
|
savepoints_threshold_exceeded? || duration_threshold_exceeded? ||
|
|
|
|
external_http_requests_threshold_exceeded?
|
2021-08-13 03:10:09 +00:00
|
|
|
end
|
|
|
|
|
|
|
|
def commit
|
|
|
|
log(:commit)
|
|
|
|
end
|
|
|
|
|
|
|
|
def rollback
|
|
|
|
log(:rollback)
|
|
|
|
end
|
|
|
|
|
2021-08-26 09:11:15 +00:00
|
|
|
def backtraces
|
|
|
|
@context[:backtraces].to_a
|
|
|
|
end
|
|
|
|
|
2022-03-15 12:07:44 +00:00
|
|
|
def external_http_requests_count
|
|
|
|
@requests_count ||= external_http_requests_count_total - @context[:external_http_count_start].to_i
|
|
|
|
end
|
|
|
|
|
|
|
|
def external_http_requests_duration
|
|
|
|
@requests_duration ||= external_http_requests_duration_total - @context[:external_http_duration_start].to_f
|
|
|
|
end
|
|
|
|
|
2021-08-13 03:10:09 +00:00
|
|
|
private
|
|
|
|
|
|
|
|
def queries
|
|
|
|
@context[:queries].to_a.join("\n")
|
|
|
|
end
|
|
|
|
|
|
|
|
def current_timestamp
|
|
|
|
::Gitlab::Metrics::System.monotonic_time
|
|
|
|
end
|
|
|
|
|
|
|
|
def logged_already?
|
|
|
|
return false if @context[:last_log_timestamp].nil?
|
|
|
|
|
|
|
|
(current_timestamp - @context[:last_log_timestamp].to_i) < LOG_THROTTLE_DURATION
|
|
|
|
end
|
|
|
|
|
|
|
|
def set_last_log_timestamp
|
|
|
|
@context[:last_log_timestamp] = current_timestamp
|
|
|
|
end
|
|
|
|
|
|
|
|
def log(operation)
|
|
|
|
return unless should_log?
|
|
|
|
|
|
|
|
set_last_log_timestamp
|
|
|
|
|
|
|
|
attributes = {
|
|
|
|
class: self.class.name,
|
|
|
|
result: operation,
|
|
|
|
duration_s: duration,
|
|
|
|
depth: @context[:depth].to_i,
|
|
|
|
savepoints_count: @context[:savepoints].to_i,
|
|
|
|
rollbacks_count: @context[:rollbacks].to_i,
|
|
|
|
releases_count: @context[:releases].to_i,
|
2022-03-15 12:07:44 +00:00
|
|
|
external_http_requests_count: external_http_requests_count,
|
|
|
|
external_http_requests_duration: external_http_requests_duration,
|
2021-08-26 09:11:15 +00:00
|
|
|
sql: queries,
|
|
|
|
savepoint_backtraces: backtraces
|
2021-08-13 03:10:09 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
application_info(attributes)
|
|
|
|
end
|
|
|
|
|
|
|
|
def application_info(attributes)
|
|
|
|
Gitlab::AppJsonLogger.info(attributes)
|
|
|
|
end
|
2022-03-15 12:07:44 +00:00
|
|
|
|
|
|
|
def external_http_requests_count_total
|
|
|
|
::Gitlab::Metrics::Subscribers::ExternalHttp.request_count.to_i
|
|
|
|
end
|
|
|
|
|
|
|
|
def external_http_requests_duration_total
|
|
|
|
::Gitlab::Metrics::Subscribers::ExternalHttp.duration.to_f
|
|
|
|
end
|
2021-08-13 03:10:09 +00:00
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|