2021-12-11 22:18:48 +05:30
|
|
|
# frozen_string_literal: true
|
|
|
|
|
|
|
|
module Gitlab
|
|
|
|
module Graphql
|
|
|
|
module Tracers
|
|
|
|
# This tracer writes logs for certain trace events.
|
|
|
|
# It reads duration metadata written by TimerTracer.
|
|
|
|
class LoggerTracer
|
|
|
|
def self.use(schema)
|
|
|
|
schema.tracer(self.new)
|
|
|
|
end
|
|
|
|
|
|
|
|
def trace(key, data)
|
2022-01-26 12:08:38 +05:30
|
|
|
yield
|
|
|
|
rescue StandardError => e
|
|
|
|
data[:exception] = e
|
|
|
|
raise e
|
|
|
|
ensure
|
2021-12-11 22:18:48 +05:30
|
|
|
case key
|
|
|
|
when "execute_query"
|
|
|
|
log_execute_query(**data)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
private
|
|
|
|
|
2022-01-26 12:08:38 +05:30
|
|
|
def log_execute_query(query: nil, duration_s: 0, exception: nil)
|
2021-12-11 22:18:48 +05:30
|
|
|
# execute_query should always have :query, but we're just being defensive
|
|
|
|
return unless query
|
|
|
|
|
|
|
|
analysis_info = query.context[:gl_analysis]&.transform_keys { |key| "query_analysis.#{key}" }
|
|
|
|
info = {
|
|
|
|
trace_type: 'execute_query',
|
|
|
|
query_fingerprint: query.fingerprint,
|
|
|
|
duration_s: duration_s,
|
|
|
|
operation_name: query.operation_name,
|
|
|
|
operation_fingerprint: query.operation_fingerprint,
|
|
|
|
is_mutation: query.mutation?,
|
|
|
|
variables: clean_variables(query.provided_variables),
|
|
|
|
query_string: query.query_string
|
|
|
|
}
|
|
|
|
|
2022-01-26 12:08:38 +05:30
|
|
|
Gitlab::ExceptionLogFormatter.format!(exception, info)
|
|
|
|
|
2021-12-11 22:18:48 +05:30
|
|
|
info.merge!(::Gitlab::ApplicationContext.current)
|
|
|
|
info.merge!(analysis_info) if analysis_info
|
|
|
|
|
|
|
|
::Gitlab::GraphqlLogger.info(info)
|
|
|
|
end
|
|
|
|
|
|
|
|
def clean_variables(variables)
|
|
|
|
filtered = ActiveSupport::ParameterFilter
|
|
|
|
.new(::Rails.application.config.filter_parameters)
|
|
|
|
.filter(variables)
|
|
|
|
|
|
|
|
filtered&.to_s
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|