Commit 5f0c230a authored by charlieablett's avatar charlieablett

Move complexity/depth to `final_value`

Tidy tests according to reviewer comments.
Move complexity and depth calls from `initial_value` to `final_value`
Log variables as json
parent d0e32c2c
...@@ -9,14 +9,11 @@ module Gitlab ...@@ -9,14 +9,11 @@ module Gitlab
end end
def initial_value(query) def initial_value(query)
analyzers = [complexity_analyzer, depth_analyzer]
complexity, depth = GraphQL::Analysis.analyze_query(query, analyzers)
{ {
time_started: Gitlab::Metrics::System.monotonic_time, time_started: Gitlab::Metrics::System.monotonic_time,
query_string: query.query_string, query_string: query.query_string,
query: query,
variables: process_variables(query.provided_variables), variables: process_variables(query.provided_variables),
complexity: complexity,
depth: depth,
duration: nil duration: nil
} }
end end
...@@ -26,16 +23,21 @@ module Gitlab ...@@ -26,16 +23,21 @@ module Gitlab
end end
def final_value(memo) def final_value(memo)
memo[:duration] = "#{duration(memo[:time_started]).round(1)}ms" analyzers = [complexity_analyzer, depth_analyzer]
GraphqlLogger.info(memo.except!(:time_started)) complexity, depth = GraphQL::Analysis.analyze_query(memo[:query], analyzers)
memo
memo[:depth] = depth
memo[:complexity] = complexity
memo[:duration] = duration(memo[:time_started]).round(1)
GraphqlLogger.info(memo.except!(:time_started, :query))
end end
private private
def process_variables(variables) def process_variables(variables)
if variables.respond_to?(:to_unsafe_h) if variables.respond_to?(:to_json)
variables.to_unsafe_h variables.to_json
else else
variables variables
end end
......
...@@ -4,19 +4,9 @@ require 'spec_helper' ...@@ -4,19 +4,9 @@ require 'spec_helper'
describe Gitlab::Graphql::QueryAnalyzers::LoggerAnalyzer do describe Gitlab::Graphql::QueryAnalyzers::LoggerAnalyzer do
subject { described_class.new } 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!(: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 before do
allow(Gitlab::Metrics::System).to receive(:monotonic_time).and_return(now) allow(Gitlab::Metrics::System).to receive(:monotonic_time).and_return(now)
end end
...@@ -27,7 +17,7 @@ describe Gitlab::Graphql::QueryAnalyzers::LoggerAnalyzer do ...@@ -27,7 +17,7 @@ describe Gitlab::Graphql::QueryAnalyzers::LoggerAnalyzer do
stub_feature_flags(graphql_logging: false) stub_feature_flags(graphql_logging: false)
end end
specify do it 'enables the analyzer' do
expect(subject.analyze?(anything)).to be_falsey expect(subject.analyze?(anything)).to be_falsey
end end
end end
......
...@@ -4,6 +4,7 @@ require 'spec_helper' ...@@ -4,6 +4,7 @@ require 'spec_helper'
describe Gitlab::GraphqlLogger do describe Gitlab::GraphqlLogger do
subject { described_class.new('/dev/null') } subject { described_class.new('/dev/null') }
let(:now) { Time.now } let(:now) { Time.now }
it 'builds a logger once' do it 'builds a logger once' do
...@@ -15,13 +16,14 @@ describe Gitlab::GraphqlLogger do ...@@ -15,13 +16,14 @@ describe Gitlab::GraphqlLogger do
context 'logging a GraphQL query' do context 'logging a GraphQL query' do
let(:query) { File.read(Rails.root.join('spec/fixtures/api/graphql/introspection.graphql')) } let(:query) { File.read(Rails.root.join('spec/fixtures/api/graphql/introspection.graphql')) }
it 'logs a query from JSON' do it 'logs a query from JSON' do
analyzer_memo = { analyzer_memo = {
query_string: query, query_string: query,
variables: {}, variables: {},
complexity: 181, complexity: 181,
depth: 0, depth: 0,
duration: "7ms" duration: 7
} }
output = subject.format_message('INFO', now, 'test', analyzer_memo) output = subject.format_message('INFO', now, 'test', analyzer_memo)
data = JSON.parse(output) data = JSON.parse(output)
...@@ -31,7 +33,7 @@ describe Gitlab::GraphqlLogger do ...@@ -31,7 +33,7 @@ describe Gitlab::GraphqlLogger do
expect(data['complexity']).to eq(181) expect(data['complexity']).to eq(181)
expect(data['variables']).to eq({}) expect(data['variables']).to eq({})
expect(data['depth']).to eq(0) expect(data['depth']).to eq(0)
expect(data['duration']).to eq("7ms") expect(data['duration']).to eq(7)
end end
end end
end end
...@@ -17,31 +17,32 @@ describe 'GraphQL' do ...@@ -17,31 +17,32 @@ describe 'GraphQL' do
end end
context 'logging' do context 'logging' do
before do shared_examples 'logging a graphql query' do
expect(Gitlab::GraphqlLogger).to receive(:info).with(expected) let(:expected_params) do
{ query_string: query, variables: variables.to_json, duration: anything, depth: 1, complexity: 1 }
end end
context 'with no variables' do it 'logs a query with the expected params' do
let(:expected) do post_graphql(query, variables: variables)
{ query_string: query, variables: {}, duration: anything, depth: 1, complexity: 1 } end
end end
it 'logs the query' do before do
post_graphql(query) expect(Gitlab::GraphqlLogger).to receive(:info).with(expected_params).once
end end
context 'with no variables' do
let(:variables) { {} }
it_behaves_like 'logging a graphql query'
end end
context 'with variables' do context 'with variables' do
let!(:variables) do let(:variables) do
{ "foo" => "bar" } { "foo" => "bar" }
end end
let(:expected) do
{ query_string: query, variables: variables, duration: anything, depth: 1, complexity: 1 }
end
it 'logs the query' do it_behaves_like 'logging a graphql query'
post_graphql(query, variables: variables)
end
end end
end end
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment