From 5d639f3f8fa9391372802d65d3d92c62ede2df41 Mon Sep 17 00:00:00 2001
From: Markus Koller <mkoller@gitlab.com>
Date: Thu, 10 Jun 2021 16:41:50 +0200
Subject: [PATCH] Use webhook context when logging rate-limit

Include the hook metadata in the log, and remove the redundant call
to `Gitlab::AppLogger` since `auth.log` is visible in Kibana as well.
---
 app/services/web_hook_service.rb       | 27 ++++++++++----------------
 spec/services/web_hook_service_spec.rb | 22 +++++++++++----------
 2 files changed, 22 insertions(+), 27 deletions(-)

diff --git a/app/services/web_hook_service.rb b/app/services/web_hook_service.rb
index f258aa133769..77d2139b3d1d 100644
--- a/app/services/web_hook_service.rb
+++ b/app/services/web_hook_service.rb
@@ -91,12 +91,10 @@ def execute
   end
 
   def async_execute
-    if rate_limited?(hook)
-      log_rate_limit(hook)
-    else
-      Gitlab::ApplicationContext.with_context(hook.application_context) do
-        WebHookWorker.perform_async(hook.id, data, hook_name)
-      end
+    Gitlab::ApplicationContext.with_context(hook.application_context) do
+      break log_rate_limit if rate_limited?
+
+      WebHookWorker.perform_async(hook.id, data, hook_name)
     end
   end
 
@@ -177,7 +175,7 @@ def safe_response_body(response)
     response.body.encode('UTF-8', invalid: :replace, undef: :replace, replace: '')
   end
 
-  def rate_limited?(hook)
+  def rate_limited?
     return false unless Feature.enabled?(:web_hooks_rate_limit, default_enabled: :yaml)
     return false if rate_limit.nil?
 
@@ -192,18 +190,13 @@ def rate_limit
     @rate_limit ||= hook.rate_limit
   end
 
-  def log_rate_limit(hook)
-    payload = {
+  def log_rate_limit
+    Gitlab::AuthLogger.error(
       message: 'Webhook rate limit exceeded',
       hook_id: hook.id,
       hook_type: hook.type,
-      hook_name: hook_name
-    }
-
-    Gitlab::AuthLogger.error(payload)
-
-    # Also log into application log for now, so we can use this information
-    # to determine suitable limits for gitlab.com
-    Gitlab::AppLogger.error(payload)
+      hook_name: hook_name,
+      **Gitlab::ApplicationContext.current
+    )
   end
 end
diff --git a/spec/services/web_hook_service_spec.rb b/spec/services/web_hook_service_spec.rb
index 9465fe7f0d66..5f53d6f34d81 100644
--- a/spec/services/web_hook_service_spec.rb
+++ b/spec/services/web_hook_service_spec.rb
@@ -375,15 +375,18 @@ def expect_to_rate_limit(hook, threshold:, throttled: false)
         it 'does not queue a worker and logs an error' do
           expect(WebHookWorker).not_to receive(:perform_async)
 
-          payload = {
-            message: 'Webhook rate limit exceeded',
-            hook_id: project_hook.id,
-            hook_type: 'ProjectHook',
-            hook_name: 'push_hooks'
-          }
-
-          expect(Gitlab::AuthLogger).to receive(:error).with(payload)
-          expect(Gitlab::AppLogger).to receive(:error).with(payload)
+          expect(Gitlab::AuthLogger).to receive(:error).with(
+            include(
+              message: 'Webhook rate limit exceeded',
+              hook_id: project_hook.id,
+              hook_type: 'ProjectHook',
+              hook_name: 'push_hooks',
+              "correlation_id" => kind_of(String),
+              "meta.project" => project.full_path,
+              "meta.related_class" => 'ProjectHook',
+              "meta.root_namespace" => project.root_namespace.full_path
+            )
+          )
 
           service_instance.async_execute
         end
@@ -403,7 +406,6 @@ def expect_to_rate_limit(hook, threshold:, throttled: false)
 
         it 'stops queueing workers and logs errors' do
           expect(Gitlab::AuthLogger).to receive(:error).twice
-          expect(Gitlab::AppLogger).to receive(:error).twice
 
           2.times { service_instance.async_execute }
         end
-- 
GitLab