From e1532aeea91810dd10b6cc39f0277798cd8c0702 Mon Sep 17 00:00:00 2001 From: Stan Hu <stanhu@gmail.com> Date: Wed, 23 Nov 2016 20:53:09 -0800 Subject: [PATCH 1/2] Add a Unicorn timeout logger to track down periodic 502 errors If a Web request takes more than 60 s to process, Unicorn will kill the process and respawn it. We should log these slow requests. Relates to https://gitlab.com/gitlab-com/infrastructure/issues/685 --- .../unreleased/unicorn-timeout-logger.yml | 4 ++ config/initializers/log_timeout.rb | 1 + .../middleware/unicorn_timeout_logger.rb | 41 +++++++++++++++++++ 3 files changed, 46 insertions(+) create mode 100644 changelogs/unreleased/unicorn-timeout-logger.yml create mode 100644 config/initializers/log_timeout.rb create mode 100644 lib/gitlab/middleware/unicorn_timeout_logger.rb diff --git a/changelogs/unreleased/unicorn-timeout-logger.yml b/changelogs/unreleased/unicorn-timeout-logger.yml new file mode 100644 index 00000000000..bc067f68ebd --- /dev/null +++ b/changelogs/unreleased/unicorn-timeout-logger.yml @@ -0,0 +1,4 @@ +--- +title: Add a Unicorn timeout logger to track down periodic 502 errors +merge_request: +author: diff --git a/config/initializers/log_timeout.rb b/config/initializers/log_timeout.rb new file mode 100644 index 00000000000..2c9b3d221d2 --- /dev/null +++ b/config/initializers/log_timeout.rb @@ -0,0 +1 @@ +Rails.application.config.middleware.use(Gitlab::Middleware::UnicornTimeoutLogger) diff --git a/lib/gitlab/middleware/unicorn_timeout_logger.rb b/lib/gitlab/middleware/unicorn_timeout_logger.rb new file mode 100644 index 00000000000..ada229604c6 --- /dev/null +++ b/lib/gitlab/middleware/unicorn_timeout_logger.rb @@ -0,0 +1,41 @@ +# Based on code from: +# http://underthehood.meltwater.com/blog/2014/03/21/debugging-unicorn-rails-timeouts +require 'unicorn' + +module Gitlab + module Middleware + class UnicornTimeoutLogger + def initialize(app) + @app = app + @timeout = load_timeout + end + + def call(env) + thr = Thread.new do + sleep(@timeout - 1) + + unless Thread.current[:done] + path = env["PATH_INFO"] + query_string = ENV["QUERY_STRING"] + path += "?#{query_string}" if query_string.present? + + Rails.logger.warn "[TIMEOUT] Unicorn worker timeout: path => #{path}" + end + end + + @app.call(env) + ensure + thr[:done] = true + thr.run if thr.alive? + end + + private + + def load_timeout + unicorn_config = File.join(Rails.root, 'config/unicorn.rb') + configurator = Unicorn::Configurator.new({ config_file: unicorn_config }) + configurator.set[:timeout] + end + end + end +end -- GitLab From b403a88ab531349d54416d4482b0dcd338494a82 Mon Sep 17 00:00:00 2001 From: Stan Hu <stanhu@gmail.com> Date: Wed, 23 Nov 2016 21:03:33 -0800 Subject: [PATCH 2/2] Only attempt to log Unicorn timeout if the file exists Prefer File.exist? to File.exists? --- lib/gitlab/middleware/unicorn_timeout_logger.rb | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/lib/gitlab/middleware/unicorn_timeout_logger.rb b/lib/gitlab/middleware/unicorn_timeout_logger.rb index ada229604c6..6da742ccd79 100644 --- a/lib/gitlab/middleware/unicorn_timeout_logger.rb +++ b/lib/gitlab/middleware/unicorn_timeout_logger.rb @@ -11,6 +11,14 @@ module Gitlab end def call(env) + if @timeout + log_timeout(env) + else + @app.call(env) + end + end + + def log_timeout(env) thr = Thread.new do sleep(@timeout - 1) @@ -33,6 +41,9 @@ module Gitlab def load_timeout unicorn_config = File.join(Rails.root, 'config/unicorn.rb') + + return unless File.exist?(unicorn_config) + configurator = Unicorn::Configurator.new({ config_file: unicorn_config }) configurator.set[:timeout] end -- GitLab