diff options
-rw-r--r-- | lib/gitlab/graphql/query_analyzers/logger_analyzer.rb | 20 | ||||
-rw-r--r-- | spec/lib/gitlab/graphql/query_analyzers/logger_analyzer_spec.rb | 16 | ||||
-rw-r--r-- | spec/lib/gitlab/graphql_logger_spec.rb | 6 | ||||
-rw-r--r-- | spec/requests/api/graphql_spec.rb | 29 |
4 files changed, 33 insertions, 38 deletions
diff --git a/lib/gitlab/graphql/query_analyzers/logger_analyzer.rb b/lib/gitlab/graphql/query_analyzers/logger_analyzer.rb index 1e49c894ecb..8119d232124 100644 --- a/lib/gitlab/graphql/query_analyzers/logger_analyzer.rb +++ b/lib/gitlab/graphql/query_analyzers/logger_analyzer.rb @@ -9,14 +9,11 @@ module Gitlab end def initial_value(query) - analyzers = [complexity_analyzer, depth_analyzer] - complexity, depth = GraphQL::Analysis.analyze_query(query, analyzers) { time_started: Gitlab::Metrics::System.monotonic_time, query_string: query.query_string, + query: query, variables: process_variables(query.provided_variables), - complexity: complexity, - depth: depth, duration: nil } end @@ -26,16 +23,21 @@ module Gitlab end def final_value(memo) - memo[:duration] = "#{duration(memo[:time_started]).round(1)}ms" - GraphqlLogger.info(memo.except!(:time_started)) - memo + analyzers = [complexity_analyzer, depth_analyzer] + complexity, depth = GraphQL::Analysis.analyze_query(memo[:query], analyzers) + + memo[:depth] = depth + memo[:complexity] = complexity + memo[:duration] = duration(memo[:time_started]).round(1) + + GraphqlLogger.info(memo.except!(:time_started, :query)) end private def process_variables(variables) - if variables.respond_to?(:to_unsafe_h) - variables.to_unsafe_h + if variables.respond_to?(:to_json) + variables.to_json else variables 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 index 4491c1cfa65..cbf35c1095a 100644 --- a/spec/lib/gitlab/graphql/query_analyzers/logger_analyzer_spec.rb +++ b/spec/lib/gitlab/graphql/query_analyzers/logger_analyzer_spec.rb @@ -4,19 +4,9 @@ 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!(:now) { Gitlab::Metrics::System.monotonic_time } - let(:complexity) { 4 } - let(:depth) { 2 } - let(:initial_values) do - { time_started: now, - query_string: query_string, - variables: provided_variables, - complexity: nil, - depth: nil, - duration: nil } - end + before do allow(Gitlab::Metrics::System).to receive(:monotonic_time).and_return(now) end @@ -27,7 +17,7 @@ describe Gitlab::Graphql::QueryAnalyzers::LoggerAnalyzer do stub_feature_flags(graphql_logging: false) end - specify do + it 'enables the analyzer' do expect(subject.analyze?(anything)).to be_falsey end end diff --git a/spec/lib/gitlab/graphql_logger_spec.rb b/spec/lib/gitlab/graphql_logger_spec.rb index 4157bb86f1c..c8d4dac2153 100644 --- a/spec/lib/gitlab/graphql_logger_spec.rb +++ b/spec/lib/gitlab/graphql_logger_spec.rb @@ -4,6 +4,7 @@ require 'spec_helper' describe Gitlab::GraphqlLogger do subject { described_class.new('/dev/null') } + let(:now) { Time.now } it 'builds a logger once' do @@ -15,13 +16,14 @@ describe Gitlab::GraphqlLogger do context 'logging a GraphQL query' do let(:query) { File.read(Rails.root.join('spec/fixtures/api/graphql/introspection.graphql')) } + it 'logs a query from JSON' do analyzer_memo = { query_string: query, variables: {}, complexity: 181, depth: 0, - duration: "7ms" + duration: 7 } output = subject.format_message('INFO', now, 'test', analyzer_memo) data = JSON.parse(output) @@ -31,7 +33,7 @@ describe Gitlab::GraphqlLogger do expect(data['complexity']).to eq(181) expect(data['variables']).to eq({}) expect(data['depth']).to eq(0) - expect(data['duration']).to eq("7ms") + expect(data['duration']).to eq(7) end end end diff --git a/spec/requests/api/graphql_spec.rb b/spec/requests/api/graphql_spec.rb index ebf223127b5..abc24fc0fe8 100644 --- a/spec/requests/api/graphql_spec.rb +++ b/spec/requests/api/graphql_spec.rb @@ -17,31 +17,32 @@ describe 'GraphQL' do end context 'logging' do + shared_examples 'logging a graphql query' do + let(:expected_params) do + { query_string: query, variables: variables.to_json, duration: anything, depth: 1, complexity: 1 } + end + + it 'logs a query with the expected params' do + post_graphql(query, variables: variables) + end + end + before do - expect(Gitlab::GraphqlLogger).to receive(:info).with(expected) + expect(Gitlab::GraphqlLogger).to receive(:info).with(expected_params).once end context 'with no variables' do - let(:expected) do - { query_string: query, variables: {}, duration: anything, depth: 1, complexity: 1 } - end + let(:variables) { {} } - it 'logs the query' do - post_graphql(query) - end + it_behaves_like 'logging a graphql query' end context 'with variables' do - let!(:variables) do + let(:variables) do { "foo" => "bar" } end - let(:expected) do - { query_string: query, variables: variables, duration: anything, depth: 1, complexity: 1 } - end - it 'logs the query' do - post_graphql(query, variables: variables) - end + it_behaves_like 'logging a graphql query' end end |