Restructure complexity analyzer

Remove instance variables for class re-use, test individual methods,
use `monotonic_time`

lib/gitlab/graphql/query_analyzers/logger_analyzer.rb

@@ -4,10 +4,6 @@ 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)
@@ -18,16 +14,20 @@ module Gitlab
         # Returns the initial value for `memo`
         def initial_value(query)
           {
-            time_started: Time.zone.now,
+            time_started: Gitlab::Metrics::System.monotonic_time,
             query_string: query.query_string,
-            variables: query.provided_variables
+            variables: process_variables(query.provided_variables),
+            complexity: nil,
+            depth: nil,
+            duration: nil
           }
         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
+          memo = set_complexity(memo)
+          set_depth(memo)
         end
 
         # Called when we're done the whole visit.
@@ -35,29 +35,37 @@ module Gitlab
         # 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))
+          GraphqlLogger.info(memo.except!(:time_started))
           memo
         end
 
         private
 
-        def set_complexity
+        def process_variables(variables)
+          if variables.respond_to?(:to_unsafe_h)
+            variables.to_unsafe_h
+          else
+            variables
+          end
+        end
+
+        def set_complexity(memo)
           GraphQL::Analysis::QueryComplexity.new do |query, complexity_value|
-            @info_hash[:complexity] = complexity_value
+            memo[:complexity] = complexity_value
           end
+          memo
         end
 
-        def set_depth
+        def set_depth(memo)
           GraphQL::Analysis::QueryDepth.new do |query, depth_value|
-            @info_hash[:depth] = depth_value
+            memo[:depth] = depth_value
           end
+          memo
         end
 
         def duration(time_started)
-          nanoseconds = Time.zone.now - time_started
-          nanoseconds / 1000000
+          nanoseconds = Gitlab::Metrics::System.monotonic_time - time_started
+          nanoseconds * 1000000
         end
       end
     end

spec/lib/gitlab/graphql/query_analyzers/logger_analyzer_spec.rb

@@ -7,21 +7,43 @@ 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(:expected_hash) do
-    { query_string: query_string,
+  let(:initial_values) do
+    { time_started: now,
+      query_string: query_string,
       variables: provided_variables,
-      complexity: complexity,
-      depth: depth }
+      complexity: nil,
+      depth: nil,
+      duration: nil }
+  end
+  before do
+    allow(Gitlab::Metrics::System).to receive(:monotonic_time).and_return(now)
   end
 
-  it 'assembles a hash' do
-    query = OpenStruct.new(query_string: query_string, provided_variables: provided_variables)
-
-    subject.initial_value(query)
+  describe '#initial_value' do
+    it 'assembles a hash with initial values' do
+      query = OpenStruct.new(query_string: query_string, provided_variables: provided_variables)
 
-    expect(subject.instance_variable_get("@info_hash")).to eq expected_hash
+      expect(subject.initial_value(query)).to eq initial_values
+    end
   end
 
+  describe '#call' do
+    before do
+      # some statements to fudge the complexity and depth
+    end
+
+    it 'sets the complexity and depth' do
+      expected_hash = { time_started: now,
+                        query_string: query_string,
+                        variables: provided_variables,
+                        complexity: nil,
+                        depth: depth,
+                        duration: complexity }
+
+      expect(subject.call(initial_values, nil, nil)).to eq expected_hash
+    end
+  end
 end

spec/requests/api/graphql/gitlab_schema_spec.rb

@@ -85,7 +85,7 @@ describe 'GitlabSchema configurations' do
 
   context 'logging' do
     it 'writes to the GraphQL log' do
-      expect(Gitlab::GraphqlLogger).to receive(:info).with(/Query Complexity/)
+      expect(Gitlab::GraphqlLogger).to receive(:info)
 
       query = File.read(Rails.root.join('spec/fixtures/api/graphql/introspection.graphql'))
 

spec/requests/api/graphql_spec.rb

@@ -17,14 +17,32 @@ describe 'GraphQL' do
   end
 
   context 'logging' do
-    it 'logs the query' do
-      expected = { query_string: query, variables: {}, duration: anything }
-
+    before do
       expect(Gitlab::GraphqlLogger).to receive(:info).with(expected)
+    end
 
-      post_graphql(query)
+    context 'with no variables' do
+      let(:expected) do
+        { query_string: query, variables: {}, duration: anything, depth: 0, complexity: 0 }
+      end
+
+      it 'logs the query' do
+        post_graphql(query)
+      end
     end
 
+    context 'with variables' do
+      let!(:variables) do
+        { foo: "bar" }
+      end
+      let(:expected) do
+        { query_string: query, variables: variables, duration: anything, depth: 0, complexity: 0 }
+      end
+
+      it 'logs the query' do
+        post_graphql(query, variables: variables)
+      end
+    end
   end
 
   context 'invalid variables' do