Flatten exception details in API and controller logs

Elasticsearch and Fluentd don't handle nested objects well: the
`exception` field is currently parsed as a string and can't be searched
with the specific keywords. As we do with Gitaly logs, flatten the
fields to `exception.class`, `exception.message`, and
`exception.backtrace` to enable better searchability.

changelogs/unreleased/sh-flatten-json-exceptions.yml

+---
+title: Flatten exception details in API and controller logs
+merge_request: 20434
+author:
+type: changed

config/initializers/lograge.rb

@@ -44,16 +44,7 @@ unless Sidekiq.server?
       # https://github.com/roidrage/lograge#logging-errors--exceptions
       exception = event.payload[:exception_object]
 
-      if exception
-        payload[:exception] = {
-          class: exception.class.name,
-          message: exception.message
-        }
-
-        if exception.backtrace
-          payload[:exception][:backtrace] = Gitlab::Profiler.clean_backtrace(exception.backtrace)
-        end
-      end
+      ::Gitlab::ExceptionLogFormatter.format!(exception, payload)
 
       payload
     end

doc/administration/logs.md

@@ -67,20 +67,18 @@ NOTE: **Note:** Starting with GitLab 12.5, if an error occurs, an
   "queue_duration": 274.35,
   "correlation_id": "KjDVUhNvvV3",
   "cpu_s": 2.837645135999999,
-  "exception": {
-    "class": "NameError",
-    "message": "undefined local variable or method `adsf' for #<Admin::DashboardController:0x00007ff3c9648588>",
-    "backtrace": [
-      "app/controllers/admin/dashboard_controller.rb:11:in `index'",
-      "ee/app/controllers/ee/admin/dashboard_controller.rb:14:in `index'",
-      "ee/lib/gitlab/ip_address_state.rb:10:in `with'",
-      "ee/app/controllers/ee/application_controller.rb:43:in `set_current_ip_address'",
-      "lib/gitlab/session.rb:11:in `with_session'",
-      "app/controllers/application_controller.rb:450:in `set_session_storage'",
-      "app/controllers/application_controller.rb:444:in `set_locale'",
-      "ee/lib/gitlab/jira/middleware.rb:19:in `call'"
-    ]
-  }
+  "exception.class": "NameError",
+  "exception.message": "undefined local variable or method `adsf' for #<Admin::DashboardController:0x00007ff3c9648588>",
+  "exception.backtrace": [
+    "app/controllers/admin/dashboard_controller.rb:11:in `index'",
+    "ee/app/controllers/ee/admin/dashboard_controller.rb:14:in `index'",
+    "ee/lib/gitlab/ip_address_state.rb:10:in `with'",
+    "ee/app/controllers/ee/application_controller.rb:43:in `set_current_ip_address'",
+    "lib/gitlab/session.rb:11:in `with_session'",
+    "app/controllers/application_controller.rb:450:in `set_session_storage'",
+    "app/controllers/application_controller.rb:444:in `set_locale'",
+    "ee/lib/gitlab/jira/middleware.rb:19:in `call'"
+  ]
 }
 ```
 

lib/gitlab/exception_log_formatter.rb

+# frozen_string_literal: true
+
+module Gitlab
+  module ExceptionLogFormatter
+    def self.format!(exception, payload)
+      return unless exception
+
+      # Elasticsearch/Fluentd don't handle nested structures well.
+      # Use periods to flatten the fields.
+      payload.merge!(
+        'exception.class' => exception.class.name,
+        'exception.message' => exception.message
+      )
+
+      if exception.backtrace
+        payload['exception.backtrace'] = Gitlab::Profiler.clean_backtrace(exception.backtrace)
+      end
+    end
+  end
+end

lib/gitlab/grape_logging/loggers/exception_logger.rb

@@ -11,19 +11,11 @@ module Gitlab
           # precedence so the logger never sees it. We need to
           # store and retrieve the exception from the environment.
           exception = request.env[::API::Helpers::API_EXCEPTION_ENV]
+          data = {}
 
-          return {} unless exception.is_a?(Exception)
+          return data unless exception.is_a?(Exception)
 
-          data = {
-            exception: {
-              class: exception.class.to_s,
-              message: exception.message
-            }
-          }
-
-          if exception.backtrace
-            data[:exception][:backtrace] = Gitlab::Profiler.clean_backtrace(exception.backtrace)
-          end
+          Gitlab::ExceptionLogFormatter.format!(exception, data)
 
           data
         end

spec/initializers/lograge_spec.rb

@@ -110,9 +110,9 @@ describe 'lograge', type: :request do
 
         log_data = JSON.parse(log_output.string)
 
-        expect(log_data['exception']['class']).to eq('RuntimeError')
-        expect(log_data['exception']['message']).to eq('bad request')
-        expect(log_data['exception']['backtrace']).to eq(Gitlab::Profiler.clean_backtrace(backtrace))
+        expect(log_data['exception.class']).to eq('RuntimeError')
+        expect(log_data['exception.message']).to eq('bad request')
+        expect(log_data['exception.backtrace']).to eq(Gitlab::Profiler.clean_backtrace(backtrace))
       end
     end
   end

spec/lib/gitlab/grape_logging/loggers/exception_logger_spec.rb

@@ -24,10 +24,8 @@ describe Gitlab::GrapeLogging::Loggers::ExceptionLogger do
 
       let(:expected) do
         {
-          exception: {
-            class: 'RuntimeError',
-            message: 'This is a test'
-          }
+          'exception.class' => 'RuntimeError',
+          'exception.message' => 'This is a test'
         }
       end
 
@@ -39,7 +37,7 @@ describe Gitlab::GrapeLogging::Loggers::ExceptionLogger do
         before do
           current_backtrace = caller
           allow(exception).to receive(:backtrace).and_return(current_backtrace)
-          expected[:exception][:backtrace] = Gitlab::Profiler.clean_backtrace(current_backtrace)
+          expected['exception.backtrace'] = Gitlab::Profiler.clean_backtrace(current_backtrace)
         end
 
         it 'includes the backtrace' do