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

3 files changed, 46 insertions, 0 deletions

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