Merge branch '17848-web-hook-logging' into 'master'

Implement Web Hooks calls logging

Closes #17848

See merge request !11027

14 files changed, 385 insertions, 98 deletions

diff --git a/spec/factories/web_hook_log.rb b/spec/factories/web_hook_log.rb
new file mode 100644
index 00000000000..230b3f6b26e
--- /dev/null
+++ b/spec/factories/web_hook_log.rb
@@ -0,0 +1,14 @@
+FactoryGirl.define do
+  factory :web_hook_log do
+    web_hook factory: :project_hook
+    trigger 'push_hooks'
+    url { generate(:url) }
+    request_headers {}
+    request_data {}
+    response_headers {}
+    response_body ''
+    response_status '200'
+    execution_duration 2.0
+    internal_error_message nil
+  end
+end
diff --git a/spec/features/admin/admin_hook_logs_spec.rb b/spec/features/admin/admin_hook_logs_spec.rb
new file mode 100644
index 00000000000..5b67f4de6ac
--- /dev/null
+++ b/spec/features/admin/admin_hook_logs_spec.rb
@@ -0,0 +1,40 @@
+require 'spec_helper'
+
+feature 'Admin::HookLogs', feature: true do
+  let(:project) { create(:project) }
+  let(:system_hook) { create(:system_hook) }
+  let(:hook_log) { create(:web_hook_log, web_hook: system_hook, internal_error_message: 'some error') }
+
+  before do
+    login_as :admin
+  end
+
+  scenario 'show list of hook logs' do
+    hook_log
+    visit edit_admin_hook_path(system_hook)
+
+    expect(page).to have_content('Recent Deliveries')
+    expect(page).to have_content(hook_log.url)
+  end
+
+  scenario 'show hook log details' do
+    hook_log
+    visit edit_admin_hook_path(system_hook)
+    click_link 'View details'
+
+    expect(page).to have_content("POST #{hook_log.url}")
+    expect(page).to have_content(hook_log.internal_error_message)
+    expect(page).to have_content('Resend Request')
+  end
+
+  scenario 'retry hook log' do
+    WebMock.stub_request(:post, system_hook.url)
+
+    hook_log
+    visit edit_admin_hook_path(system_hook)
+    click_link 'View details'
+    click_link 'Resend Request'
+
+    expect(current_path).to eq(edit_admin_hook_path(system_hook))
+  end
+end
diff --git a/spec/features/admin/admin_hooks_spec.rb b/spec/features/admin/admin_hooks_spec.rb
index c5f24d412d7..80f7ec43c06 100644
--- a/spec/features/admin/admin_hooks_spec.rb
+++ b/spec/features/admin/admin_hooks_spec.rb
@@ -58,10 +58,19 @@ describe 'Admin::Hooks', feature: true do
   end
 
   describe 'Remove existing hook' do
-    it 'remove existing hook' do
-      visit admin_hooks_path
+    context 'removes existing hook' do
+      it 'from hooks list page' do
+        visit admin_hooks_path
+
+        expect { click_link 'Remove' }.to change(SystemHook, :count).by(-1)
+      end
 
-      expect { click_link 'Remove' }.to change(SystemHook, :count).by(-1)
+      it 'from hook edit page' do
+        visit admin_hooks_path
+        click_link 'Edit'
+
+        expect { click_link 'Remove' }.to change(SystemHook, :count).by(-1)
+      end
     end
   end
 
diff --git a/spec/features/projects/settings/integration_settings_spec.rb b/spec/features/projects/settings/integration_settings_spec.rb
index d3232f0cc16..fbaea14a2be 100644
--- a/spec/features/projects/settings/integration_settings_spec.rb
+++ b/spec/features/projects/settings/integration_settings_spec.rb
@@ -85,11 +85,55 @@ feature 'Integration settings', feature: true do
         expect(current_path).to eq(integrations_path)
       end
 
-      scenario 'remove existing webhook' do
-        hook
-        visit integrations_path
+      context 'remove existing webhook' do
+        scenario 'from webhooks list page' do
+          hook
+          visit integrations_path
+
+          expect { click_link 'Remove' }.to change(ProjectHook, :count).by(-1)
+        end
+
+        scenario 'from webhook edit page' do
+          hook
+          visit integrations_path
+          click_link 'Edit'
+
+          expect { click_link 'Remove' }.to change(ProjectHook, :count).by(-1)
+        end
+      end
+    end
+
+    context 'Webhook logs' do
+      let(:hook) { create(:project_hook, project: project) }
+      let(:hook_log) { create(:web_hook_log, web_hook: hook, internal_error_message: 'some error') }
+
+      scenario 'show list of hook logs' do
+        hook_log
+        visit edit_namespace_project_hook_path(project.namespace, project, hook)
+
+        expect(page).to have_content('Recent Deliveries')
+        expect(page).to have_content(hook_log.url)
+      end
+
+      scenario 'show hook log details' do
+        hook_log
+        visit edit_namespace_project_hook_path(project.namespace, project, hook)
+        click_link 'View details'
+
+        expect(page).to have_content("POST #{hook_log.url}")
+        expect(page).to have_content(hook_log.internal_error_message)
+        expect(page).to have_content('Resend Request')
+      end
+
+      scenario 'retry hook log' do
+        WebMock.stub_request(:post, hook.url)
+
+        hook_log
+        visit edit_namespace_project_hook_path(project.namespace, project, hook)
+        click_link 'View details'
+        click_link 'Resend Request'
 
-        expect { click_link 'Remove' }.to change(ProjectHook, :count).by(-1)
+        expect(current_path).to eq(edit_namespace_project_hook_path(project.namespace, project, hook))
       end
     end
   end
diff --git a/spec/lib/gitlab/import_export/all_models.yml b/spec/lib/gitlab/import_export/all_models.yml
index 34f617e23a5..2e9646286df 100644
--- a/spec/lib/gitlab/import_export/all_models.yml
+++ b/spec/lib/gitlab/import_export/all_models.yml
@@ -131,6 +131,7 @@ services:
 - service_hook
 hooks:
 - project
+- web_hook_logs
 protected_branches:
 - project
 - merge_access_levels
diff --git a/spec/models/ci/pipeline_spec.rb b/spec/models/ci/pipeline_spec.rb
index 56b24ce62f3..c8023dc13b1 100644
--- a/spec/models/ci/pipeline_spec.rb
+++ b/spec/models/ci/pipeline_spec.rb
@@ -965,7 +965,7 @@ describe Ci::Pipeline, models: true do
     end
 
     before do
-      ProjectWebHookWorker.drain
+      WebHookWorker.drain
     end
 
     context 'with pipeline hooks enabled' do
diff --git a/spec/models/hooks/service_hook_spec.rb b/spec/models/hooks/service_hook_spec.rb
index 1a83c836652..57454d2a773 100644
--- a/spec/models/hooks/service_hook_spec.rb
+++ b/spec/models/hooks/service_hook_spec.rb
@@ -1,36 +1,19 @@
-require "spec_helper"
+require 'spec_helper'
 
 describe ServiceHook, models: true do
-  describe "Associations" do
+  describe 'associations' do
     it { is_expected.to belong_to :service }
   end
 
-  describe "execute" do
-    before(:each) do
-      @service_hook = create(:service_hook)
-      @data = { project_id: 1, data: {} }
+  describe 'execute' do
+    let(:hook) { build(:service_hook) }
+    let(:data) { { key: 'value' } }
 
-      WebMock.stub_request(:post, @service_hook.url)
-    end
-
-    it "POSTs to the webhook URL" do
-      @service_hook.execute(@data)
-      expect(WebMock).to have_requested(:post, @service_hook.url).with(
-        headers: { 'Content-Type' => 'application/json', 'X-Gitlab-Event' => 'Service Hook' }
-      ).once
-    end
-
-    it "POSTs the data as JSON" do
-      @service_hook.execute(@data)
-      expect(WebMock).to have_requested(:post, @service_hook.url).with(
-        headers: { 'Content-Type' => 'application/json', 'X-Gitlab-Event' => 'Service Hook' }
-      ).once
-    end
-
-    it "catches exceptions" do
-      expect(WebHook).to receive(:post).and_raise("Some HTTP Post error")
+    it '#execute' do
+      expect(WebHookService).to receive(:new).with(hook, data, 'service_hook').and_call_original
+      expect_any_instance_of(WebHookService).to receive(:execute)
 
-      expect { @service_hook.execute(@data) }.to raise_error(RuntimeError)
+      hook.execute(data)
     end
   end
 end
diff --git a/spec/models/hooks/system_hook_spec.rb b/spec/models/hooks/system_hook_spec.rb
index 4340170888d..0d2b622132e 100644
--- a/spec/models/hooks/system_hook_spec.rb
+++ b/spec/models/hooks/system_hook_spec.rb
@@ -126,4 +126,26 @@ describe SystemHook, models: true do
       expect(SystemHook.repository_update_hooks).to eq([hook])
     end
   end
+
+  describe 'execute WebHookService' do
+    let(:hook) { build(:system_hook) }
+    let(:data) { { key: 'value' } }
+    let(:hook_name) { 'system_hook' }
+
+    before do
+      expect(WebHookService).to receive(:new).with(hook, data, hook_name).and_call_original
+    end
+
+    it '#execute' do
+      expect_any_instance_of(WebHookService).to receive(:execute)
+
+      hook.execute(data, hook_name)
+    end
+
+    it '#async_execute' do
+      expect_any_instance_of(WebHookService).to receive(:async_execute)
+
+      hook.async_execute(data, hook_name)
+    end
+  end
 end
diff --git a/spec/models/hooks/web_hook_log_spec.rb b/spec/models/hooks/web_hook_log_spec.rb
new file mode 100644
index 00000000000..c649cf3b589
--- /dev/null
+++ b/spec/models/hooks/web_hook_log_spec.rb
@@ -0,0 +1,30 @@
+require 'rails_helper'
+
+describe WebHookLog, models: true do
+  it { is_expected.to belong_to(:web_hook) }
+
+  it { is_expected.to serialize(:request_headers).as(Hash) }
+  it { is_expected.to serialize(:request_data).as(Hash) }
+  it { is_expected.to serialize(:response_headers).as(Hash) }
+
+  it { is_expected.to validate_presence_of(:web_hook) }
+
+  describe '#success?' do
+    let(:web_hook_log) { build(:web_hook_log, response_status: status) }
+
+    describe '2xx' do
+      let(:status) { '200' }
+      it { expect(web_hook_log.success?).to be_truthy }
+    end
+
+    describe 'not 2xx' do
+      let(:status) { '500' }
+      it { expect(web_hook_log.success?).to be_falsey }
+    end
+
+    describe 'internal erorr' do
+      let(:status) { 'internal error' }
+      it { expect(web_hook_log.success?).to be_falsey }
+    end
+  end
+end
diff --git a/spec/models/hooks/web_hook_spec.rb b/spec/models/hooks/web_hook_spec.rb
index 9d4db1bfb52..53157c24477 100644
--- a/spec/models/hooks/web_hook_spec.rb
+++ b/spec/models/hooks/web_hook_spec.rb
@@ -1,89 +1,54 @@
 require 'spec_helper'
 
 describe WebHook, models: true do
-  describe "Validations" do
+  let(:hook) { build(:project_hook) }
+
+  describe 'associations' do
+    it { is_expected.to have_many(:web_hook_logs).dependent(:destroy) }
+  end
+
+  describe 'validations' do
     it { is_expected.to validate_presence_of(:url) }
 
     describe 'url' do
-      it { is_expected.to allow_value("http://example.com").for(:url) }
-      it { is_expected.to allow_value("https://example.com").for(:url) }
-      it { is_expected.to allow_value(" https://example.com ").for(:url) }
-      it { is_expected.to allow_value("http://test.com/api").for(:url) }
-      it { is_expected.to allow_value("http://test.com/api?key=abc").for(:url) }
-      it { is_expected.to allow_value("http://test.com/api?key=abc&type=def").for(:url) }
+      it { is_expected.to allow_value('http://example.com').for(:url) }
+      it { is_expected.to allow_value('https://example.com').for(:url) }
+      it { is_expected.to allow_value(' https://example.com ').for(:url) }
+      it { is_expected.to allow_value('http://test.com/api').for(:url) }
+      it { is_expected.to allow_value('http://test.com/api?key=abc').for(:url) }
+      it { is_expected.to allow_value('http://test.com/api?key=abc&type=def').for(:url) }
 
-      it { is_expected.not_to allow_value("example.com").for(:url) }
-      it { is_expected.not_to allow_value("ftp://example.com").for(:url) }
-      it { is_expected.not_to allow_value("herp-and-derp").for(:url) }
+      it { is_expected.not_to allow_value('example.com').for(:url) }
+      it { is_expected.not_to allow_value('ftp://example.com').for(:url) }
+      it { is_expected.not_to allow_value('herp-and-derp').for(:url) }
 
       it 'strips :url before saving it' do
-        hook = create(:project_hook, url: ' https://example.com ')
+        hook.url = ' https://example.com '
+        hook.save
 
         expect(hook.url).to eq('https://example.com')
       end
     end
   end
 
-  describe "execute" do
-    let(:project) { create(:empty_project) }
-    let(:project_hook) { create(:project_hook) }
-
-    before(:each) do
-      project.hooks << [project_hook]
-      @data = { before: 'oldrev', after: 'newrev', ref: 'ref' }
-
-      WebMock.stub_request(:post, project_hook.url)
-    end
-
-    context 'when token is defined' do
-      let(:project_hook) { create(:project_hook, :token) }
-
-      it 'POSTs to the webhook URL' do
-        project_hook.execute(@data, 'push_hooks')
-        expect(WebMock).to have_requested(:post, project_hook.url).with(
-          headers: { 'Content-Type' => 'application/json',
-                     'X-Gitlab-Event' => 'Push Hook',
-                     'X-Gitlab-Token' => project_hook.token }
-        ).once
-      end
-    end
-
-    it "POSTs to the webhook URL" do
-      project_hook.execute(@data, 'push_hooks')
-      expect(WebMock).to have_requested(:post, project_hook.url).with(
-        headers: { 'Content-Type' => 'application/json', 'X-Gitlab-Event' => 'Push Hook' }
-      ).once
-    end
-
-    it "POSTs the data as JSON" do
-      project_hook.execute(@data, 'push_hooks')
-      expect(WebMock).to have_requested(:post, project_hook.url).with(
-        headers: { 'Content-Type' => 'application/json', 'X-Gitlab-Event' => 'Push Hook' }
-      ).once
-    end
-
-    it "catches exceptions" do
-      expect(WebHook).to receive(:post).and_raise("Some HTTP Post error")
-
-      expect { project_hook.execute(@data, 'push_hooks') }.to raise_error(RuntimeError)
-    end
-
-    it "handles SSL exceptions" do
-      expect(WebHook).to receive(:post).and_raise(OpenSSL::SSL::SSLError.new('SSL error'))
+  describe 'execute' do
+    let(:data) { { key: 'value' } }
+    let(:hook_name) { 'project hook' }
 
-      expect(project_hook.execute(@data, 'push_hooks')).to eq([false, 'SSL error'])
+    before do
+      expect(WebHookService).to receive(:new).with(hook, data, hook_name).and_call_original
     end
 
-    it "handles 200 status code" do
-      WebMock.stub_request(:post, project_hook.url).to_return(status: 200, body: "Success")
+    it '#execute' do
+      expect_any_instance_of(WebHookService).to receive(:execute)
 
-      expect(project_hook.execute(@data, 'push_hooks')).to eq([200, 'Success'])
+      hook.execute(data, hook_name)
     end
 
-    it "handles 2xx status codes" do
-      WebMock.stub_request(:post, project_hook.url).to_return(status: 201, body: "Success")
+    it '#async_execute' do
+      expect_any_instance_of(WebHookService).to receive(:async_execute)
 
-      expect(project_hook.execute(@data, 'push_hooks')).to eq([201, 'Success'])
+      hook.async_execute(data, hook_name)
     end
   end
 end
diff --git a/spec/routing/admin_routing_spec.rb b/spec/routing/admin_routing_spec.rb
index e5fc0b676af..179fc9733ad 100644
--- a/spec/routing/admin_routing_spec.rb
+++ b/spec/routing/admin_routing_spec.rb
@@ -103,6 +103,18 @@ describe Admin::HooksController, "routing" do
   end
 end
 
+# admin_hook_hook_log_retry GET    /admin/hooks/:hook_id/hook_logs/:id/retry(.:format) admin/hook_logs#retry
+# admin_hook_hook_log       GET    /admin/hooks/:hook_id/hook_logs/:id(.:format)       admin/hook_logs#show
+describe Admin::HookLogsController, 'routing' do
+  it 'to #retry' do
+    expect(get('/admin/hooks/1/hook_logs/1/retry')).to route_to('admin/hook_logs#retry', hook_id: '1', id: '1')
+  end
+
+  it 'to #show' do
+    expect(get('/admin/hooks/1/hook_logs/1')).to route_to('admin/hook_logs#show', hook_id: '1', id: '1')
+  end
+end
+
 # admin_logs GET    /admin/logs(.:format) admin/logs#show
 describe Admin::LogsController, "routing" do
   it "to #show" do
diff --git a/spec/routing/project_routing_spec.rb b/spec/routing/project_routing_spec.rb
index a391c046f92..54417f6b3e1 100644
--- a/spec/routing/project_routing_spec.rb
+++ b/spec/routing/project_routing_spec.rb
@@ -349,6 +349,18 @@ describe 'project routing' do
     end
   end
 
+  # retry_namespace_project_hook_hook_log GET /:project_id/hooks/:hook_id/hook_logs/:id/retry(.:format) projects/hook_logs#retry
+  # namespace_project_hook_hook_log       GET /:project_id/hooks/:hook_id/hook_logs/:id(.:format)       projects/hook_logs#show
+  describe Projects::HookLogsController, 'routing' do
+    it 'to #retry' do
+      expect(get('/gitlab/gitlabhq/hooks/1/hook_logs/1/retry')).to route_to('projects/hook_logs#retry', namespace_id: 'gitlab', project_id: 'gitlabhq', hook_id: '1', id: '1')
+    end
+
+    it 'to #show' do
+      expect(get('/gitlab/gitlabhq/hooks/1/hook_logs/1')).to route_to('projects/hook_logs#show', namespace_id: 'gitlab', project_id: 'gitlabhq', hook_id: '1', id: '1')
+    end
+  end
+
   # project_commit GET    /:project_id/commit/:id(.:format) commit#show {id: /\h{7,40}/, project_id: /[^\/]+/}
   describe Projects::CommitController, 'routing' do
     it 'to #show' do
diff --git a/spec/services/web_hook_service_spec.rb b/spec/services/web_hook_service_spec.rb
new file mode 100644
index 00000000000..b5abc46e80c
--- /dev/null
+++ b/spec/services/web_hook_service_spec.rb
@@ -0,0 +1,137 @@
+require 'spec_helper'
+
+describe WebHookService, services: true do
+  let(:project) { create(:empty_project) }
+  let(:project_hook) { create(:project_hook) }
+  let(:headers) do
+    {
+      'Content-Type' => 'application/json',
+      'X-Gitlab-Event' => 'Push Hook'
+    }
+  end
+  let(:data) do
+    { before: 'oldrev', after: 'newrev', ref: 'ref' }
+  end
+  let(:service_instance) { WebHookService.new(project_hook, data, 'push_hooks') }
+
+  describe '#execute' do
+    before(:each) do
+      project.hooks << [project_hook]
+
+      WebMock.stub_request(:post, project_hook.url)
+    end
+
+    context 'when token is defined' do
+      let(:project_hook) { create(:project_hook, :token) }
+
+      it 'POSTs to the webhook URL' do
+        service_instance.execute
+        expect(WebMock).to have_requested(:post, project_hook.url).with(
+          headers: headers.merge({ 'X-Gitlab-Token' => project_hook.token })
+        ).once
+      end
+    end
+
+    it 'POSTs to the webhook URL' do
+      service_instance.execute
+      expect(WebMock).to have_requested(:post, project_hook.url).with(
+        headers: headers
+      ).once
+    end
+
+    it 'POSTs the data as JSON' do
+      service_instance.execute
+      expect(WebMock).to have_requested(:post, project_hook.url).with(
+        headers: headers
+      ).once
+    end
+
+    it 'catches exceptions' do
+      WebMock.stub_request(:post, project_hook.url).to_raise(StandardError.new('Some error'))
+
+      expect { service_instance.execute }.to raise_error(StandardError)
+    end
+
+    it 'handles exceptions' do
+      exceptions = [SocketError, OpenSSL::SSL::SSLError, Errno::ECONNRESET, Errno::ECONNREFUSED, Net::OpenTimeout]
+      exceptions.each do |exception_class|
+        exception = exception_class.new('Exception message')
+
+        WebMock.stub_request(:post, project_hook.url).to_raise(exception)
+        expect(service_instance.execute).to eq([nil, exception.message])
+        expect { service_instance.execute }.not_to raise_error
+      end
+    end
+
+    it 'handles 200 status code' do
+      WebMock.stub_request(:post, project_hook.url).to_return(status: 200, body: 'Success')
+
+      expect(service_instance.execute).to eq([200, 'Success'])
+    end
+
+    it 'handles 2xx status codes' do
+      WebMock.stub_request(:post, project_hook.url).to_return(status: 201, body: 'Success')
+
+      expect(service_instance.execute).to eq([201, 'Success'])
+    end
+
+    context 'execution logging' do
+      let(:hook_log) { project_hook.web_hook_logs.last }
+
+      context 'with success' do
+        before do
+          WebMock.stub_request(:post, project_hook.url).to_return(status: 200, body: 'Success')
+          service_instance.execute
+        end
+
+        it 'log successful execution' do
+          expect(hook_log.trigger).to eq('push_hooks')
+          expect(hook_log.url).to eq(project_hook.url)
+          expect(hook_log.request_headers).to eq(headers)
+          expect(hook_log.response_body).to eq('Success')
+          expect(hook_log.response_status).to eq('200')
+          expect(hook_log.execution_duration).to be > 0
+          expect(hook_log.internal_error_message).to be_nil
+        end
+      end
+
+      context 'with exception' do
+        before do
+          WebMock.stub_request(:post, project_hook.url).to_raise(SocketError.new('Some HTTP Post error'))
+          service_instance.execute
+        end
+
+        it 'log failed execution' do
+          expect(hook_log.trigger).to eq('push_hooks')
+          expect(hook_log.url).to eq(project_hook.url)
+          expect(hook_log.request_headers).to eq(headers)
+          expect(hook_log.response_body).to eq('')
+          expect(hook_log.response_status).to eq('internal error')
+          expect(hook_log.execution_duration).to be > 0
+          expect(hook_log.internal_error_message).to eq('Some HTTP Post error')
+        end
+      end
+
+      context 'should not log ServiceHooks' do
+        let(:service_hook) { create(:service_hook) }
+        let(:service_instance) { WebHookService.new(service_hook, data, 'service_hook') }
+
+        before do
+          WebMock.stub_request(:post, service_hook.url).to_return(status: 200, body: 'Success')
+        end
+
+        it { expect { service_instance.execute }.not_to change(WebHookLog, :count) }
+      end
+    end
+  end
+
+  describe '#async_execute' do
+    let(:system_hook) { create(:system_hook) }
+    
+    it 'enqueue WebHookWorker' do
+      expect(Sidekiq::Client).to receive(:enqueue).with(WebHookWorker, project_hook.id, data, 'push_hooks')
+
+      WebHookService.new(project_hook, data, 'push_hooks').async_execute
+    end
+  end
+end
diff --git a/spec/workers/remove_old_web_hook_logs_worker_spec.rb b/spec/workers/remove_old_web_hook_logs_worker_spec.rb
new file mode 100644
index 00000000000..6d26ba5dfa0
--- /dev/null
+++ b/spec/workers/remove_old_web_hook_logs_worker_spec.rb
@@ -0,0 +1,18 @@
+require 'spec_helper'
+
+describe RemoveOldWebHookLogsWorker do
+  subject { described_class.new }
+
+  describe '#perform' do
+    let!(:week_old_record) { create(:web_hook_log, created_at: Time.now - 1.week) }
+    let!(:three_days_old_record) { create(:web_hook_log, created_at: Time.now - 3.days) }
+    let!(:one_day_old_record) { create(:web_hook_log, created_at: Time.now - 1.day) }
+
+    it 'removes web hook logs older than 2 days' do
+      subject.perform
+
+      expect(WebHookLog.all).to include(one_day_old_record)
+      expect(WebHookLog.all).not_to include(week_old_record, three_days_old_record)
+    end
+  end
+end