diff options
| -rw-r--r-- | app/graphql/gitlab_schema.rb | 2 | ||||
| -rw-r--r-- | lib/gitlab/graphql/query_analyzers/log_query_complexity.rb | 18 | ||||
| -rw-r--r-- | lib/gitlab/graphql/query_analyzers/logger_analyzer.rb | 65 | ||||
| -rw-r--r-- | lib/gitlab/graphql_logger.rb | 12 | ||||
| -rw-r--r-- | spec/lib/gitlab/graphql/query_analyzers/logger_analyzer_spec.rb | 27 | ||||
| -rw-r--r-- | spec/lib/gitlab/graphql_logger_spec.rb | 12 | ||||
| -rw-r--r-- | spec/requests/api/graphql_spec.rb | 11 |
7 files changed, 108 insertions, 39 deletions
diff --git a/app/graphql/gitlab_schema.rb b/app/graphql/gitlab_schema.rb index a63f45f231c..f8ad6bee21b 100644 --- a/app/graphql/gitlab_schema.rb +++ b/app/graphql/gitlab_schema.rb @@ -16,7 +16,7 @@ class GitlabSchema < GraphQL::Schema use Gitlab::Graphql::Connections use Gitlab::Graphql::GenericTracing - query_analyzer Gitlab::Graphql::QueryAnalyzers::LogQueryComplexity.analyzer + query_analyzer Gitlab::Graphql::QueryAnalyzers::LoggerAnalyzer.new query(Types::QueryType) diff --git a/lib/gitlab/graphql/query_analyzers/log_query_complexity.rb b/lib/gitlab/graphql/query_analyzers/log_query_complexity.rb deleted file mode 100644 index d3e21946357..00000000000 --- a/lib/gitlab/graphql/query_analyzers/log_query_complexity.rb +++ /dev/null @@ -1,18 +0,0 @@ -# frozen_string_literal: true - -module Gitlab - module Graphql - module QueryAnalyzers - class LogQueryComplexity - class << self - def analyzer - GraphQL::Analysis::QueryComplexity.new do |query, complexity| - # temporary until https://gitlab.com/gitlab-org/gitlab-ce/issues/59587 - GraphqlLogger.info("[Query Complexity] #{complexity} | admin? #{query.context[:current_user]&.admin?}") - end - end - end - end - end - end -end diff --git a/lib/gitlab/graphql/query_analyzers/logger_analyzer.rb b/lib/gitlab/graphql/query_analyzers/logger_analyzer.rb new file mode 100644 index 00000000000..3796eefd608 --- /dev/null +++ b/lib/gitlab/graphql/query_analyzers/logger_analyzer.rb @@ -0,0 +1,65 @@ +# frozen_string_literal: true + +module Gitlab + module Graphql + module QueryAnalyzers + class LoggerAnalyzer + def initialize + @info_hash = {} + end + + # Called before initializing the analyzer. + # Returns true to run this analyzer, or false to skip it. + def analyze?(query) + true # unless there's some reason why we wouldn't log? + end + + # Called before the visit. + # Returns the initial value for `memo` + def initial_value(query) + { + time_started: Time.zone.now, + query_string: query.query_string, + variables: query.provided_variables + } + end + + # This is like the `reduce` callback. + # The return value is passed to the next call as `memo` + def call(memo, visit_type, irep_node) + memo + end + + # Called when we're done the whole visit. + # The return value may be a GraphQL::AnalysisError (or an array of them). + # Or, you can use this hook to write to a log, etc + def final_value(memo) + memo[:duration] = "#{duration(memo[:time_started]).round(1)}ms" + set_complexity + set_depth + GraphqlLogger.info(memo.except!(:time_started).merge(@info_hash)) + memo + end + + private + + def set_complexity + GraphQL::Analysis::QueryComplexity.new do |query, complexity_value| + @info_hash[:complexity] = complexity_value + end + end + + def set_depth + GraphQL::Analysis::QueryDepth.new do |query, depth_value| + @info_hash[:depth] = depth_value + end + end + + def duration(time_started) + nanoseconds = Time.zone.now - time_started + nanoseconds / 1000000 + end + end + end + end +end diff --git a/lib/gitlab/graphql_logger.rb b/lib/gitlab/graphql_logger.rb index aff3ff5f48d..43d917908b6 100644 --- a/lib/gitlab/graphql_logger.rb +++ b/lib/gitlab/graphql_logger.rb @@ -1,19 +1,9 @@ # frozen_string_literal: true module Gitlab - class GraphqlLogger < Gitlab::Logger + class GraphqlLogger < Gitlab::JsonLogger def self.file_name_noext 'graphql_json' end - - # duration - # complexity - # depth - # sanitized variables (?) - # a structured representation of the query (?) - - def format_message(severity, timestamp, progname, msg) - "#{timestamp.to_s(:long)}: #{msg}\n" - end end end diff --git a/spec/lib/gitlab/graphql/query_analyzers/logger_analyzer_spec.rb b/spec/lib/gitlab/graphql/query_analyzers/logger_analyzer_spec.rb new file mode 100644 index 00000000000..53a1d7f8e42 --- /dev/null +++ b/spec/lib/gitlab/graphql/query_analyzers/logger_analyzer_spec.rb @@ -0,0 +1,27 @@ +# frozen_string_literal: true + +require 'spec_helper' + +describe Gitlab::Graphql::QueryAnalyzers::LoggerAnalyzer do + + subject { described_class.new } + let(:query_string) { "abc" } + let(:provided_variables) { { a: 1, b: 2, c: 3 } } + let(:complexity) { 4 } + let(:depth) { 2 } + let(:expected_hash) do + { query_string: query_string, + variables: provided_variables, + complexity: complexity, + depth: depth } + end + + it 'assembles a hash' do + query = OpenStruct.new(query_string: query_string, provided_variables: provided_variables) + + subject.initial_value(query) + + expect(subject.instance_variable_get("@info_hash")).to eq expected_hash + end + +end diff --git a/spec/lib/gitlab/graphql_logger_spec.rb b/spec/lib/gitlab/graphql_logger_spec.rb index 51c77181927..aeeed0b2ca1 100644 --- a/spec/lib/gitlab/graphql_logger_spec.rb +++ b/spec/lib/gitlab/graphql_logger_spec.rb @@ -1,6 +1,8 @@ +# frozen_string_literal: true + require 'spec_helper' -describe Gitlab::GraphqlLogger, :request_store do +describe Gitlab::GraphqlLogger do subject { described_class.new('/dev/null') } let(:now) { Time.now } @@ -10,12 +12,4 @@ describe Gitlab::GraphqlLogger, :request_store do subject.info('hello world') subject.error('hello again') end - - describe '#format_message' do - it 'formats properly' do - output = subject.format_message('INFO', now, 'test', 'Hello world') - - expect(output).to match(/Hello world/) - end - end end diff --git a/spec/requests/api/graphql_spec.rb b/spec/requests/api/graphql_spec.rb index cca87c16f27..103b02ba7a7 100644 --- a/spec/requests/api/graphql_spec.rb +++ b/spec/requests/api/graphql_spec.rb @@ -16,6 +16,17 @@ describe 'GraphQL' do end end + context 'logging' do + it 'logs the query' do + expected = { query_string: query, variables: {}, duration: anything } + + expect(Gitlab::GraphqlLogger).to receive(:info).with(expected) + + post_graphql(query) + end + + end + context 'invalid variables' do it 'returns an error' do post_graphql(query, variables: "This is not JSON") |