Apply reviewer feedback59587-add-graphql-logging

- Comply doc with guidelines
- Improve tests for readability and completeness
- Separate out phases visually with newlines
- Add `format_message` test
- test readability
- code and test structure/styling
- static query analyzers
- call `as_json` on `provided_variables`
- add exception handling

2 files changed, 41 insertions, 16 deletions

diff --git a/spec/requests/api/graphql/gitlab_schema_spec.rb b/spec/requests/api/graphql/gitlab_schema_spec.rb
index 510dec5edb2..1017e409f6c 100644
--- a/spec/requests/api/graphql/gitlab_schema_spec.rb
+++ b/spec/requests/api/graphql/gitlab_schema_spec.rb
@@ -83,31 +83,38 @@ describe 'GitlabSchema configurations' do
     end
   end
 
+  context 'when IntrospectionQuery' do
+    it 'is not too complex' do
+      query = File.read(Rails.root.join('spec/fixtures/api/graphql/introspection.graphql'))
+
+      post_graphql(query, current_user: nil)
+
+      expect(graphql_errors).to be_nil
+    end
+  end
+
   context 'logging' do
     let(:query) { File.read(Rails.root.join('spec/fixtures/api/graphql/introspection.graphql')) }
 
-    it 'logs the query complexity' do
+    it 'logs the query complexity and depth' do
       analyzer_memo = {
-          query_string: query,
-          variables: {},
-          complexity: 181,
-          depth: 0,
-          duration: "7ms"
+        query_string: query,
+        variables: {}.to_s,
+        complexity: 181,
+        depth: 0,
+        duration: 7
       }
+
       expect_any_instance_of(Gitlab::Graphql::QueryAnalyzers::LoggerAnalyzer).to receive(:duration).and_return(7)
       expect(Gitlab::GraphqlLogger).to receive(:info).with(analyzer_memo)
 
       post_graphql(query, current_user: nil)
     end
-  end
 
-  context 'when IntrospectionQuery' do
-    it 'is not too complex' do
-      query = File.read(Rails.root.join('spec/fixtures/api/graphql/introspection.graphql'))
+    it 'logs using `format_message`' do
+      expect_any_instance_of(Gitlab::GraphqlLogger).to receive(:format_message)
 
       post_graphql(query, current_user: nil)
-
-      expect(graphql_errors).to be_nil
     end
   end
 end
diff --git a/spec/requests/api/graphql_spec.rb b/spec/requests/api/graphql_spec.rb
index abc24fc0fe8..656d6f8b50b 100644
--- a/spec/requests/api/graphql_spec.rb
+++ b/spec/requests/api/graphql_spec.rb
@@ -19,16 +19,21 @@ describe 'GraphQL' do
   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 }
+        { query_string: query, variables: variables.to_s, duration: anything, depth: 1, complexity: 1 }
       end
 
       it 'logs a query with the expected params' do
+        expect(Gitlab::GraphqlLogger).to receive(:info).with(expected_params).once
+
         post_graphql(query, variables: variables)
       end
-    end
 
-    before do
-      expect(Gitlab::GraphqlLogger).to receive(:info).with(expected_params).once
+      it 'does not instantiate any query analyzers' do # they are static and re-used
+        expect(GraphQL::Analysis::QueryComplexity).not_to receive(:new)
+        expect(GraphQL::Analysis::QueryDepth).not_to receive(:new)
+
+        2.times { post_graphql(query, variables: variables) }
+      end
     end
 
     context 'with no variables' do
@@ -44,6 +49,19 @@ describe 'GraphQL' do
 
       it_behaves_like 'logging a graphql query'
     end
+
+    context 'when there is an error in the logger' do
+      before do
+        allow_any_instance_of(Gitlab::Graphql::QueryAnalyzers::LoggerAnalyzer).to receive(:process_variables).and_raise(StandardError.new("oh noes!"))
+      end
+
+      it 'logs the exception in Sentry and continues with the request' do
+        expect(Gitlab::Sentry).to receive(:track_exception).at_least(1).times
+        expect(Gitlab::GraphqlLogger).to receive(:info)
+
+        post_graphql(query, variables: {})
+      end
+    end
   end
 
   context 'invalid variables' do