Commit 1ed7b762 authored by Dmitriy Zaporozhets's avatar Dmitriy Zaporozhets

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

Implement Web Hooks calls logging

Closes #17848

See merge request !11027
parents 78de1c05 330789c2
class Admin::HookLogsController < Admin::ApplicationController
include HooksExecution
before_action :hook, only: [:show, :retry]
before_action :hook_log, only: [:show, :retry]
respond_to :html
def show
end
def retry
status, message = hook.execute(hook_log.request_data, hook_log.trigger)
set_hook_execution_notice(status, message)
redirect_to edit_admin_hook_path(@hook)
end
private
def hook
@hook ||= SystemHook.find(params[:hook_id])
end
def hook_log
@hook_log ||= hook.web_hook_logs.find(params[:id])
end
end
class Admin::HooksController < Admin::ApplicationController class Admin::HooksController < Admin::ApplicationController
before_action :hook, only: :edit include HooksExecution
before_action :hook_logs, only: :edit
def index def index
@hooks = SystemHook.all @hooks = SystemHook.all
...@@ -36,15 +38,9 @@ class Admin::HooksController < Admin::ApplicationController ...@@ -36,15 +38,9 @@ class Admin::HooksController < Admin::ApplicationController
end end
def test def test
data = { status, message = hook.execute(sample_hook_data, 'system_hooks')
event_name: "project_create",
name: "Ruby", set_hook_execution_notice(status, message)
path: "ruby",
project_id: 1,
owner_name: "Someone",
owner_email: "example@gitlabhq.com"
}
hook.execute(data, 'system_hooks')
redirect_back_or_default redirect_back_or_default
end end
...@@ -55,6 +51,11 @@ class Admin::HooksController < Admin::ApplicationController ...@@ -55,6 +51,11 @@ class Admin::HooksController < Admin::ApplicationController
@hook ||= SystemHook.find(params[:id]) @hook ||= SystemHook.find(params[:id])
end end
def hook_logs
@hook_logs ||=
Kaminari.paginate_array(hook.web_hook_logs.order(created_at: :desc)).page(params[:page])
end
def hook_params def hook_params
params.require(:hook).permit( params.require(:hook).permit(
:enable_ssl_verification, :enable_ssl_verification,
...@@ -65,4 +66,15 @@ class Admin::HooksController < Admin::ApplicationController ...@@ -65,4 +66,15 @@ class Admin::HooksController < Admin::ApplicationController
:url :url
) )
end end
def sample_hook_data
{
event_name: "project_create",
name: "Ruby",
path: "ruby",
project_id: 1,
owner_name: "Someone",
owner_email: "example@gitlabhq.com"
}
end
end end
module HooksExecution
extend ActiveSupport::Concern
private
def set_hook_execution_notice(status, message)
if status && status >= 200 && status < 400
flash[:notice] = "Hook executed successfully: HTTP #{status}"
elsif status
flash[:alert] = "Hook executed successfully but returned HTTP #{status} #{message}"
else
flash[:alert] = "Hook execution failed: #{message}"
end
end
end
class Projects::HookLogsController < Projects::ApplicationController
include HooksExecution
before_action :authorize_admin_project!
before_action :hook, only: [:show, :retry]
before_action :hook_log, only: [:show, :retry]
respond_to :html
layout 'project_settings'
def show
end
def retry
status, message = hook.execute(hook_log.request_data, hook_log.trigger)
set_hook_execution_notice(status, message)
redirect_to edit_namespace_project_hook_path(@project.namespace, @project, @hook)
end
private
def hook
@hook ||= @project.hooks.find(params[:hook_id])
end
def hook_log
@hook_log ||= hook.web_hook_logs.find(params[:id])
end
end
class Projects::HooksController < Projects::ApplicationController class Projects::HooksController < Projects::ApplicationController
include HooksExecution
# Authorize # Authorize
before_action :authorize_admin_project! before_action :authorize_admin_project!
before_action :hook, only: :edit before_action :hook_logs, only: :edit
respond_to :html respond_to :html
...@@ -34,13 +36,7 @@ class Projects::HooksController < Projects::ApplicationController ...@@ -34,13 +36,7 @@ class Projects::HooksController < Projects::ApplicationController
if !@project.empty_repo? if !@project.empty_repo?
status, message = TestHookService.new.execute(hook, current_user) status, message = TestHookService.new.execute(hook, current_user)
if status && status >= 200 && status < 400 set_hook_execution_notice(status, message)
flash[:notice] = "Hook executed successfully: HTTP #{status}"
elsif status
flash[:alert] = "Hook executed successfully but returned HTTP #{status} #{message}"
else
flash[:alert] = "Hook execution failed: #{message}"
end
else else
flash[:alert] = 'Hook execution failed. Ensure the project has commits.' flash[:alert] = 'Hook execution failed. Ensure the project has commits.'
end end
...@@ -60,6 +56,11 @@ class Projects::HooksController < Projects::ApplicationController ...@@ -60,6 +56,11 @@ class Projects::HooksController < Projects::ApplicationController
@hook ||= @project.hooks.find(params[:id]) @hook ||= @project.hooks.find(params[:id])
end end
def hook_logs
@hook_logs ||=
Kaminari.paginate_array(hook.web_hook_logs.order(created_at: :desc)).page(params[:page])
end
def hook_params def hook_params
params.require(:hook).permit( params.require(:hook).permit(
:job_events, :job_events,
......
...@@ -2,6 +2,6 @@ class ServiceHook < WebHook ...@@ -2,6 +2,6 @@ class ServiceHook < WebHook
belongs_to :service belongs_to :service
def execute(data) def execute(data)
super(data, 'service_hook') WebHookService.new(self, data, 'service_hook').execute
end end
end end
...@@ -3,8 +3,4 @@ class SystemHook < WebHook ...@@ -3,8 +3,4 @@ class SystemHook < WebHook
default_value_for :push_events, false default_value_for :push_events, false
default_value_for :repository_update_events, true default_value_for :repository_update_events, true
def async_execute(data, hook_name)
Sidekiq::Client.enqueue(SystemHookWorker, id, data, hook_name)
end
end end
class WebHook < ActiveRecord::Base class WebHook < ActiveRecord::Base
include Sortable include Sortable
include HTTParty
default_value_for :push_events, true default_value_for :push_events, true
default_value_for :issues_events, false default_value_for :issues_events, false
...@@ -13,52 +12,18 @@ class WebHook < ActiveRecord::Base ...@@ -13,52 +12,18 @@ class WebHook < ActiveRecord::Base
default_value_for :repository_update_events, false default_value_for :repository_update_events, false
default_value_for :enable_ssl_verification, true default_value_for :enable_ssl_verification, true
has_many :web_hook_logs, dependent: :destroy
scope :push_hooks, -> { where(push_events: true) } scope :push_hooks, -> { where(push_events: true) }
scope :tag_push_hooks, -> { where(tag_push_events: true) } scope :tag_push_hooks, -> { where(tag_push_events: true) }
# HTTParty timeout
default_timeout Gitlab.config.gitlab.webhook_timeout
validates :url, presence: true, url: true validates :url, presence: true, url: true
def execute(data, hook_name) def execute(data, hook_name)
parsed_url = URI.parse(url) WebHookService.new(self, data, hook_name).execute
if parsed_url.userinfo.blank?
response = WebHook.post(url,
body: data.to_json,
headers: build_headers(hook_name),
verify: enable_ssl_verification)
else
post_url = url.gsub("#{parsed_url.userinfo}@", '')
auth = {
username: CGI.unescape(parsed_url.user),
password: CGI.unescape(parsed_url.password)
}
response = WebHook.post(post_url,
body: data.to_json,
headers: build_headers(hook_name),
verify: enable_ssl_verification,
basic_auth: auth)
end
[response.code, response.to_s]
rescue SocketError, OpenSSL::SSL::SSLError, Errno::ECONNRESET, Errno::ECONNREFUSED, Net::OpenTimeout => e
logger.error("WebHook Error => #{e}")
[false, e.to_s]
end end
def async_execute(data, hook_name) def async_execute(data, hook_name)
Sidekiq::Client.enqueue(ProjectWebHookWorker, id, data, hook_name) WebHookService.new(self, data, hook_name).async_execute
end
private
def build_headers(hook_name)
headers = {
'Content-Type' => 'application/json',
'X-Gitlab-Event' => hook_name.singularize.titleize
}
headers['X-Gitlab-Token'] = token if token.present?
headers
end end
end end
class WebHookLog < ActiveRecord::Base
belongs_to :web_hook
serialize :request_headers, Hash
serialize :request_data, Hash
serialize :response_headers, Hash
validates :web_hook, presence: true
def success?
response_status =~ /^2/
end
end
class WebHookService
class InternalErrorResponse
attr_reader :body, :headers, :code
def initialize
@headers = HTTParty::Response::Headers.new({})
@body = ''
@code = 'internal error'
end
end
include HTTParty
# HTTParty timeout
default_timeout Gitlab.config.gitlab.webhook_timeout
attr_accessor :hook, :data, :hook_name
def initialize(hook, data, hook_name)
@hook = hook
@data = data
@hook_name = hook_name
end
def execute
start_time = Time.now
response = if parsed_url.userinfo.blank?
make_request(hook.url)
else
make_request_with_auth
end
log_execution(
trigger: hook_name,
url: hook.url,
request_data: data,
response: response,
execution_duration: Time.now - start_time
)
[response.code, response.to_s]
rescue SocketError, OpenSSL::SSL::SSLError, Errno::ECONNRESET, Errno::ECONNREFUSED, Net::OpenTimeout => e
log_execution(
trigger: hook_name,
url: hook.url,
request_data: data,
response: InternalErrorResponse.new,
execution_duration: Time.now - start_time,
error_message: e.to_s
)
Rails.logger.error("WebHook Error => #{e}")
[nil, e.to_s]
end
def async_execute
Sidekiq::Client.enqueue(WebHookWorker, hook.id, data, hook_name)
end
private
def parsed_url
@parsed_url ||= URI.parse(hook.url)
end
def make_request(url, basic_auth = false)
self.class.post(url,
body: data.to_json,
headers: build_headers(hook_name),
verify: hook.enable_ssl_verification,
basic_auth: basic_auth)
end
def make_request_with_auth
post_url = hook.url.gsub("#{parsed_url.userinfo}@", '')
basic_auth = {
username: CGI.unescape(parsed_url.user),
password: CGI.unescape(parsed_url.password)
}
make_request(post_url, basic_auth)
end
def log_execution(trigger:, url:, request_data:, response:, execution_duration:, error_message: nil)
# logging for ServiceHook's is not available
return if hook.is_a?(ServiceHook)
WebHookLog.create(
web_hook: hook,
trigger: trigger,
url: url,
execution_duration: execution_duration,
request_headers: build_headers(hook_name),
request_data: request_data,
response_headers: format_response_headers(response),
response_body: response.body,
response_status: response.code,
internal_error_message: error_message
)
end
def build_headers(hook_name)
@headers ||= begin
{
'Content-Type' => 'application/json',
'X-Gitlab-Event' => hook_name.singularize.titleize
}.tap do |hash|
hash['X-Gitlab-Token'] = hook.token if hook.token.present?
end
end
end
# Make response headers more stylish
# Net::HTTPHeader has downcased hash with arrays: { 'content-type' => ['text/html; charset=utf-8'] }
# This method format response to capitalized hash with strings: { 'Content-Type' => 'text/html; charset=utf-8' }
def format_response_headers(response)
response.headers.each_capitalized.to_h
end
end
.row.prepend-top-default.append-bottom-default
.col-lg-3
%h4.prepend-top-0
Recent Deliveries
%p When an event in GitLab triggers a webhook, you can use the request details to figure out if something went wrong.
.col-lg-9
- if hook_logs.any?
%table.table
%thead
%tr
%th Status
%th Trigger
%th URL
%th Elapsed time
%th Request time
%th
- hook_logs.each do |hook_log|
%tr
%td
= render partial: 'shared/hook_logs/status_label', locals: { hook_log: hook_log }
%td.hidden-xs
%span.label.label-gray.deploy-project-label
= hook_log.trigger.singularize.titleize
%td
= truncate(hook_log.url, length: 50)
%td.light
#{number_with_precision(hook_log.execution_duration, precision: 2)} ms
%td.light
= time_ago_with_tooltip(hook_log.created_at)
%td
= link_to 'View details', admin_hook_hook_log_path(hook, hook_log)
= paginate hook_logs, theme: 'gitlab'
- else
.settings-message.text-center
You don't have any webhooks deliveries
- page_title 'Request details'
%h3.page-title
Request details
%hr
= link_to 'Resend Request', retry_admin_hook_hook_log_path(@hook, @hook_log), class: "btn btn-default pull-right prepend-left-10"
= render partial: 'shared/hook_logs/content', locals: { hook_log: @hook_log }
...@@ -12,3 +12,9 @@ ...@@ -12,3 +12,9 @@
= render partial: 'form', locals: { form: f, hook: @hook } = render partial: 'form', locals: { form: f, hook: @hook }
.form-actions .form-actions
= f.submit 'Save changes', class: 'btn btn-create' = f.submit 'Save changes', class: 'btn btn-create'
= link_to 'Test hook', test_admin_hook_path(@hook), class: 'btn btn-default'
= link_to 'Remove', admin_hook_path(@hook), method: :delete, class: 'btn btn-remove pull-right', data: { confirm: 'Are you sure?' }
%hr
= render partial: 'admin/hook_logs/index', locals: { hook: @hook, hook_logs: @hook_logs }
...@@ -17,7 +17,7 @@ ...@@ -17,7 +17,7 @@
= link_to admin_broadcast_messages_path, title: 'Messages' do = link_to admin_broadcast_messages_path, title: 'Messages' do
%span %span
Messages Messages
= nav_link(controller: :hooks) do = nav_link(controller: [:hooks, :hook_logs]) do
= link_to admin_hooks_path, title: 'Hooks' do = link_to admin_hooks_path, title: 'Hooks' do
%span %span
System Hooks System Hooks
......
.row.prepend-top-default.append-bottom-default
.col-lg-3
%h4.prepend-top-0
Recent Deliveries
%p When an event in GitLab triggers a webhook, you can use the request details to figure out if something went wrong.
.col-lg-9
- if hook_logs.any?
%table.table
%thead
%tr
%th Status
%th Trigger
%th URL
%th Elapsed time
%th Request time
%th
- hook_logs.each do |hook_log|
%tr
%td
= render partial: 'shared/hook_logs/status_label', locals: { hook_log: hook_log }
%td.hidden-xs
%span.label.label-gray.deploy-project-label
= hook_log.trigger.singularize.titleize
%td
= truncate(hook_log.url, length: 50)
%td.light
#{number_with_precision(hook_log.execution_duration, precision: 2)} ms
%td.light
= time_ago_with_tooltip(hook_log.created_at)
%td
= link_to 'View details', namespace_project_hook_hook_log_path(project.namespace, project, hook, hook_log)
= paginate hook_logs, theme: 'gitlab'
- else
.settings-message.text-center
You don't have any webhooks deliveries
= render 'projects/settings/head'
.row.prepend-top-default.append-bottom-default
.col-lg-3
%h4.prepend-top-0
Request details
.col-lg-9
= link_to 'Resend Request', retry_namespace_project_hook_hook_log_path(@project.namespace, @project, @hook, @hook_log), class: "btn btn-default pull-right prepend-left-10"
= render partial: 'shared/hook_logs/content', locals: { hook_log: @hook_log }
- page_title 'Integrations'
= render 'projects/settings/head' = render 'projects/settings/head'
.row.prepend-top-default .row.prepend-top-default
...@@ -10,5 +11,12 @@ ...@@ -10,5 +11,12 @@
.col-lg-9.append-bottom-default .col-lg-9.append-bottom-default
= form_for [@project.namespace.becomes(Namespace), @project, @hook], as: :hook, url: namespace_project_hook_path do |f| = form_for [@project.namespace.becomes(Namespace), @project, @hook], as: :hook, url: namespace_project_hook_path do |f|
= render partial: 'shared/web_hooks/form', locals: { form: f, hook: @hook } = render partial: 'shared/web_hooks/form', locals: { form: f, hook: @hook }
= f.submit 'Save changes', class: 'btn btn-create' = f.submit 'Save changes', class: 'btn btn-create'
= link_to 'Test hook', test_namespace_project_hook_path(@project.namespace, @project, @hook), class: 'btn btn-default'
= link_to 'Remove', namespace_project_hook_path(@project.namespace, @project, @hook), method: :delete, class: 'btn btn-remove pull-right', data: { confirm: 'Are you sure?' }
%hr
= render partial: 'projects/hook_logs/index', locals: { hook: @hook, hook_logs: @hook_logs, project: @project }
...@@ -14,7 +14,7 @@ ...@@ -14,7 +14,7 @@
%span %span
Members Members
- if can_edit - if can_edit
= nav_link(controller: [:integrations, :services, :hooks]) do = nav_link(controller: [:integrations, :services, :hooks, :hook_logs]) do
= link_to project_settings_integrations_path(@project), title: 'Integrations' do = link_to project_settings_integrations_path(@project), title: 'Integrations' do
%span %span
Integrations Integrations
......
%p
%strong Request URL:
POST
= hook_log.url
= render partial: 'shared/hook_logs/status_label', locals: { hook_log: hook_log }
%p
%strong Trigger:
%td.hidden-xs
%span.label.label-gray.deploy-project-label
= hook_log.trigger.singularize.titleize
%p
%strong Elapsed time:
#{number_with_precision(hook_log.execution_duration, precision: 2)} ms
%p
%strong Request time:
= time_ago_with_tooltip(hook_log.created_at)
%hr
- if hook_log.internal_error_message.present?
.bs-callout.bs-callout-danger
= hook_log.internal_error_message
%h5 Request headers:
%pre
- hook_log.request_headers.each do |k,v|
<strong>#{k}:</strong> #{v}
%br
%h5 Request body:
%pre
:plain
#{JSON.pretty_generate(hook_log.request_data)}
%h5 Response headers:
%pre
- hook_log.response_headers.each do |k,v|
<strong>#{k}:</strong> #{v}
%br
%h5 Response body:
%pre
:plain
#{hook_log.response_body}
- label_status = hook_log.success? ? 'label-success' : 'label-danger'
%span{ class: "label #{label_status}" }
= hook_log.response_status
class RemoveOldWebHookLogsWorker
include Sidekiq::Worker
include CronjobQueue
WEB_HOOK_LOG_LIFETIME = 2.days
def perform
WebHookLog.destroy_all(['created_at < ?', Time.now - WEB_HOOK_LOG_LIFETIME])
end
end
class SystemHookWorker
include Sidekiq::Worker
include DedicatedSidekiqQueue
sidekiq_options retry: 4
def perform(hook_id, data, hook_name)
SystemHook.find(hook_id).execute(data, hook_name)
end
end
class ProjectWebHookWorker class WebHookWorker
include Sidekiq::Worker include Sidekiq::Worker
include DedicatedSidekiqQueue include DedicatedSidekiqQueue
sidekiq_options retry: 4 sidekiq_options retry: 4
def perform(hook_id, data, hook_name) def perform(hook_id, data, hook_name)
hook = WebHook.find(hook_id)
data = data.with_indifferent_access data = data.with_indifferent_access
WebHook.find(hook_id).execute(data, hook_name)
WebHookService.new(hook, data, hook_name).execute
end end
end end
---
title: Implement web hook logging
merge_request: 11027
author: Alexander Randa
...@@ -368,11 +368,14 @@ Settings.cron_jobs['gitlab_usage_ping_worker'] ||= Settingslogic.new({}) ...@@ -368,11 +368,14 @@ Settings.cron_jobs['gitlab_usage_ping_worker'] ||= Settingslogic.new({})
Settings.cron_jobs['gitlab_usage_ping_worker']['cron'] ||= Settings.__send__(:cron_random_weekly_time) Settings.cron_jobs['gitlab_usage_ping_worker']['cron'] ||= Settings.__send__(:cron_random_weekly_time)
Settings.cron_jobs['gitlab_usage_ping_worker']['job_class'] = 'GitlabUsagePingWorker' Settings.cron_jobs['gitlab_usage_ping_worker']['job_class'] = 'GitlabUsagePingWorker'
# Every day at 00:30
Settings.cron_jobs['schedule_update_user_activity_worker'] ||= Settingslogic.new({}) Settings.cron_jobs['schedule_update_user_activity_worker'] ||= Settingslogic.new({})
Settings.cron_jobs['schedule_update_user_activity_worker']['cron'] ||= '30 0 * * *' Settings.cron_jobs['schedule_update_user_activity_worker']['cron'] ||= '30 0 * * *'
Settings.cron_jobs['schedule_update_user_activity_worker']['job_class'] = 'ScheduleUpdateUserActivityWorker' Settings.cron_jobs['schedule_update_user_activity_worker']['job_class'] = 'ScheduleUpdateUserActivityWorker'
Settings.cron_jobs['remove_old_web_hook_logs_worker'] ||= Settingslogic.new({})
Settings.cron_jobs['remove_old_web_hook_logs_worker']['cron'] ||= '40 0 * * *'
Settings.cron_jobs['remove_old_web_hook_logs_worker']['job_class'] = 'RemoveOldWebHookLogsWorker'
# #
# GitLab Shell # GitLab Shell
# #
......
...@@ -54,6 +54,12 @@ namespace :admin do ...@@ -54,6 +54,12 @@ namespace :admin do
member do member do
get :test get :test
end end
resources :hook_logs, only: [:show] do
member do
get :retry
end
end
end end
resources :broadcast_messages, only: [:index, :edit, :create, :update, :destroy] do resources :broadcast_messages, only: [:index, :edit, :create, :update, :destroy] do
......
...@@ -216,6 +216,12 @@ constraints(ProjectUrlConstrainer.new) do ...@@ -216,6 +216,12 @@ constraints(ProjectUrlConstrainer.new) do
member do member do
get :test get :test
end end
resources :hook_logs, only: [:show] do
member do
get :retry
end
end
end end
resources :container_registry, only: [:index, :destroy], resources :container_registry, only: [:index, :destroy],
......
...@@ -44,9 +44,8 @@ ...@@ -44,9 +44,8 @@
- [project_cache, 1] - [project_cache, 1]
- [project_destroy, 1] - [project_destroy, 1]
- [project_export, 1] - [project_export, 1]
- [project_web_hook, 1] - [web_hook, 1]
- [repository_check, 1] - [repository_check, 1]
- [system_hook, 1]
- [git_garbage_collect, 1] - [git_garbage_collect, 1]
- [reactive_caching, 1] - [reactive_caching, 1]
- [cronjob, 1] - [cronjob, 1]
......
# rubocop:disable all
class CreateWebHookLogs < ActiveRecord::Migration
DOWNTIME = false
def change
create_table :web_hook_logs do |t|
t.references :web_hook, null: false, index: true, foreign_key: { on_delete: :cascade }
t.string :trigger
t.string :url
t.text :request_headers
t.text :request_data
t.text :response_headers
t.text :response_body
t.string :response_status
t.float :execution_duration
t.string :internal_error_message
t.timestamps null: false
end
end
end
...@@ -1391,6 +1391,23 @@ ActiveRecord::Schema.define(version: 20170523091700) do ...@@ -1391,6 +1391,23 @@ ActiveRecord::Schema.define(version: 20170523091700) do
add_index "users_star_projects", ["project_id"], name: "index_users_star_projects_on_project_id", using: :btree add_index "users_star_projects", ["project_id"], name: "index_users_star_projects_on_project_id", using: :btree
add_index "users_star_projects", ["user_id", "project_id"], name: "index_users_star_projects_on_user_id_and_project_id", unique: true, using: :btree add_index "users_star_projects", ["user_id", "project_id"], name: "index_users_star_projects_on_user_id_and_project_id", unique: true, using: :btree
create_table "web_hook_logs", force: :cascade do |t|
t.integer "web_hook_id", null: false
t.string "trigger"
t.string "url"
t.text "request_headers"
t.text "request_data"
t.text "response_headers"
t.text "response_body"
t.string "response_status"
t.float "execution_duration"
t.string "internal_error_message"
t.datetime "created_at", null: false
t.datetime "updated_at", null: false
end
add_index "web_hook_logs", ["web_hook_id"], name: "index_web_hook_logs_on_web_hook_id", using: :btree
create_table "web_hooks", force: :cascade do |t| create_table "web_hooks", force: :cascade do |t|
t.string "url", limit: 2000 t.string "url", limit: 2000
t.integer "project_id" t.integer "project_id"
...@@ -1454,4 +1471,5 @@ ActiveRecord::Schema.define(version: 20170523091700) do ...@@ -1454,4 +1471,5 @@ ActiveRecord::Schema.define(version: 20170523091700) do
add_foreign_key "timelogs", "merge_requests", name: "fk_timelogs_merge_requests_merge_request_id", on_delete: :cascade add_foreign_key "timelogs", "merge_requests", name: "fk_timelogs_merge_requests_merge_request_id", on_delete: :cascade
add_foreign_key "trending_projects", "projects", on_delete: :cascade add_foreign_key "trending_projects", "projects", on_delete: :cascade
add_foreign_key "u2f_registrations", "users" add_foreign_key "u2f_registrations", "users"
add_foreign_key "web_hook_logs", "web_hooks", on_delete: :cascade
end end
...@@ -1017,6 +1017,22 @@ X-Gitlab-Event: Build Hook ...@@ -1017,6 +1017,22 @@ X-Gitlab-Event: Build Hook
} }
``` ```
## Troubleshoot webhooks
Gitlab stores each perform of the webhook.
You can find records for last 2 days in "Recent Deliveries" section on the edit page of each webhook.
![Recent deliveries](img/webhook_logs.png)
In this section you can see HTTP status code (green for 200-299 codes, red for the others, `internal error` for failed deliveries ), triggered event, a time when the event was called, elapsed time of the request.
If you need more information about execution, you can click `View details` link.
On this page, you can see data that GitLab sends (request headers and body) and data that it received (response headers and body).
From this page, you can repeat delivery with the same data by clicking `Resend Request` button.
>**Note:** If URL or secret token of the webhook were updated, data will be delivered to the new address.
## Example webhook receiver ## Example webhook receiver
If you want to see GitLab's webhooks in action for testing purposes you can use If you want to see GitLab's webhooks in action for testing purposes you can use
......
Feature: Project Hooks
Background:
Given I sign in as a user
And I own project "Shop"
Scenario: I should see hook list
Given project has hook
When I visit project hooks page
Then I should see project hook
Scenario: I add new hook
Given I visit project hooks page
When I submit new hook
Then I should see newly created hook
Scenario: I add new hook with SSL verification enabled
Given I visit project hooks page
When I submit new hook with SSL verification enabled
Then I should see newly created hook with SSL verification enabled
Scenario: I test hook
Given project has hook
And I visit project hooks page
When I click test hook button
Then hook should be triggered
Scenario: I test a hook on empty project
Given I own empty project with hook
And I visit project hooks page
When I click test hook button
Then I should see hook error message
Scenario: I test a hook on down URL
Given project has hook
And I visit project hooks page
When I click test hook button with invalid URL
Then I should see hook service down error message
require 'webmock'
class Spinach::Features::ProjectHooks < Spinach::FeatureSteps
include SharedAuthentication
include SharedProject
include SharedPaths
include RSpec::Matchers
include RSpec::Mocks::ExampleMethods
include WebMock::API
step 'project has hook' do
@hook = create(:project_hook, project: current_project)
end
step 'I own empty project with hook' do
@project = create(:empty_project,
name: 'Empty Project', namespace: @user.namespace)
@hook = create(:project_hook, project: current_project)
end
step 'I should see project hook' do
expect(page).to have_content @hook.url
end
step 'I submit new hook' do
@url = 'http://example.org/1'
fill_in "hook_url", with: @url
expect { click_button "Add webhook" }.to change(ProjectHook, :count).by(1)
end
step 'I submit new hook with SSL verification enabled' do
@url = 'http://example.org/2'
fill_in "hook_url", with: @url
check "hook_enable_ssl_verification"
expect { click_button "Add webhook" }.to change(ProjectHook, :count).by(1)
end
step 'I should see newly created hook' do
expect(current_path).to eq namespace_project_settings_integrations_path(current_project.namespace, current_project)
expect(page).to have_content(@url)
end
step 'I should see newly created hook with SSL verification enabled' do
expect(current_path).to eq namespace_project_settings_integrations_path(current_project.namespace, current_project)
expect(page).to have_content(@url)
expect(page).to have_content("SSL Verification: enabled")
end
step 'I click test hook button' do
stub_request(:post, @hook.url).to_return(status: 200)
click_link 'Test'
end
step 'I click test hook button with invalid URL' do
stub_request(:post, @hook.url).to_raise(SocketError)
click_link 'Test'
end
step 'hook should be triggered' do
expect(current_path).to eq namespace_project_settings_integrations_path(current_project.namespace, current_project)
expect(page).to have_selector '.flash-notice',
text: 'Hook executed successfully: HTTP 200'
end
step 'I should see hook error message' do
expect(page).to have_selector '.flash-alert',
text: 'Hook execution failed. '\
'Ensure the project has commits.'
end
step 'I should see hook service down error message' do
expect(page).to have_selector '.flash-alert',
text: 'Hook execution failed: Exception from'
end
end
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
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
...@@ -58,10 +58,19 @@ describe 'Admin::Hooks', feature: true do ...@@ -58,10 +58,19 @@ describe 'Admin::Hooks', feature: true do
end end
describe 'Remove existing hook' do describe 'Remove existing hook' do
it 'remove existing hook' do context 'removes existing hook' do
visit admin_hooks_path 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
end end
......
...@@ -85,11 +85,55 @@ feature 'Integration settings', feature: true do ...@@ -85,11 +85,55 @@ feature 'Integration settings', feature: true do
expect(current_path).to eq(integrations_path) expect(current_path).to eq(integrations_path)
end end
scenario 'remove existing webhook' do context 'remove existing webhook' do
hook scenario 'from webhooks list page' do
visit integrations_path 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 end
end end
......
...@@ -131,6 +131,7 @@ services: ...@@ -131,6 +131,7 @@ services:
- service_hook - service_hook
hooks: hooks:
- project - project
- web_hook_logs
protected_branches: protected_branches:
- project - project
- merge_access_levels - merge_access_levels
......
...@@ -965,7 +965,7 @@ describe Ci::Pipeline, models: true do ...@@ -965,7 +965,7 @@ describe Ci::Pipeline, models: true do
end end
before do before do
ProjectWebHookWorker.drain WebHookWorker.drain
end end
context 'with pipeline hooks enabled' do context 'with pipeline hooks enabled' do
......
require "spec_helper" require 'spec_helper'
describe ServiceHook, models: true do describe ServiceHook, models: true do
describe "Associations" do describe 'associations' do
it { is_expected.to belong_to :service } it { is_expected.to belong_to :service }
end end
describe "execute" do describe 'execute' do
before(:each) do let(:hook) { build(:service_hook) }
@service_hook = create(:service_hook) let(:data) { { key: 'value' } }
@data = { project_id: 1, data: {} }
WebMock.stub_request(:post, @service_hook.url) it '#execute' do
end expect(WebHookService).to receive(:new).with(hook, data, 'service_hook').and_call_original
expect_any_instance_of(WebHookService).to receive(:execute)
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")
expect { @service_hook.execute(@data) }.to raise_error(RuntimeError) hook.execute(data)
end end
end end
end end
...@@ -126,4 +126,26 @@ describe SystemHook, models: true do ...@@ -126,4 +126,26 @@ describe SystemHook, models: true do
expect(SystemHook.repository_update_hooks).to eq([hook]) expect(SystemHook.repository_update_hooks).to eq([hook])
end end
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 end
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
require 'spec_helper' require 'spec_helper'
describe WebHook, models: true do 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) } it { is_expected.to validate_presence_of(:url) }
describe 'url' do describe 'url' do
it { is_expected.to allow_value("http://example.com").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(" 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').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').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://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('example.com').for(:url) }
it { is_expected.not_to allow_value("ftp://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('herp-and-derp').for(:url) }
it 'strips :url before saving it' do 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') expect(hook.url).to eq('https://example.com')
end end
end end
end end
describe "execute" do describe 'execute' do
let(:project) { create(:empty_project) } let(:data) { { key: 'value' } }
let(:project_hook) { create(:project_hook) } let(:hook_name) { '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'))
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 end
it "handles 200 status code" do it '#execute' do
WebMock.stub_request(:post, project_hook.url).to_return(status: 200, body: "Success") 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 end
it "handles 2xx status codes" do it '#async_execute' do
WebMock.stub_request(:post, project_hook.url).to_return(status: 201, body: "Success") 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 end
end end
...@@ -103,6 +103,18 @@ describe Admin::HooksController, "routing" do ...@@ -103,6 +103,18 @@ describe Admin::HooksController, "routing" do
end end
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 # admin_logs GET /admin/logs(.:format) admin/logs#show
describe Admin::LogsController, "routing" do describe Admin::LogsController, "routing" do
it "to #show" do it "to #show" do
......
...@@ -349,6 +349,18 @@ describe 'project routing' do ...@@ -349,6 +349,18 @@ describe 'project routing' do
end end
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: /[^\/]+/} # project_commit GET /:project_id/commit/:id(.:format) commit#show {id: /\h{7,40}/, project_id: /[^\/]+/}
describe Projects::CommitController, 'routing' do describe Projects::CommitController, 'routing' do
it 'to #show' do it 'to #show' do
......
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
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
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment