FEATURE: enable_performance_http_headers for performance diagnostics

FEATURE: enable_performance_http_headers for performance diagnostics

This adds support for DISCOURSE_ENABLE_PERFORMANCE_HTTP_HEADERS when set to true this will turn on performance related headers

X-Redis-Calls: 10     # number of redis calls
X-Redis-Time: 1.02    # redis time in seconds
X-Sql-Commands: 102   # number of SQL commands
X-Sql-Time: 1.02      # duration in SQL in seconds
X-Queue-Time: 1.01    # time the request sat in queue (depends on NGINX)

To get queue time NGINX must provide: HTTP_X_REQUEST_START

We do not recommend you enable this without thinking, it exposes information about what your page is doing, usually you would only enable this if you intend to strip off the headers further down the stream in a proxy

diff --git a/config/discourse_defaults.conf b/config/discourse_defaults.conf
index bf4e8e3..e66ed46 100644
--- a/config/discourse_defaults.conf
+++ b/config/discourse_defaults.conf
@@ -239,3 +239,13 @@ refresh_maxmind_db_during_precompile_days = 2
 # backup path containing maxmind db files
 maxmind_backup_path =
 
+# when enabled the following headers will be added to every response:
+# (note, if measurements do not exist for the header they will be omitted)
+#
+# X-Redis-Calls: 10
+# X-Redis-Time: 1.02
+# X-Sql-Calls: 102
+# X-Sql-Time: 1.02
+# X-Queue-Time: 1.01
+enable_performance_http_headers = false
+
diff --git a/config/initializers/200-message_bus_request_tracker.rb b/config/initializers/200-message_bus_request_tracker.rb
index 1026912..c0ebcfc 100644
--- a/config/initializers/200-message_bus_request_tracker.rb
+++ b/config/initializers/200-message_bus_request_tracker.rb
@@ -16,4 +16,8 @@ Rails.configuration.middleware = Rails.configuration.middleware + session_operat
 if Rails.env != 'development' || ENV['TRACK_REQUESTS']
   require 'middleware/request_tracker'
   Rails.configuration.middleware.unshift Middleware::RequestTracker
+
+  if GlobalSetting.enable_performance_http_headers
+    MethodProfiler.ensure_discourse_instrumentation!
+  end
 end
diff --git a/lib/middleware/request_tracker.rb b/lib/middleware/request_tracker.rb
index e8af3b5..470ab5f 100644
--- a/lib/middleware/request_tracker.rb
+++ b/lib/middleware/request_tracker.rb
@@ -165,6 +165,20 @@ class Middleware::RequestTracker
     # possibly transferred?
     if info && (headers = result[1])
       headers["X-Runtime"] = "%0.6f" % info[:total_duration]
+
+      if GlobalSetting.enable_performance_http_headers
+        if redis = info[:redis]
+          headers["X-Redis-Calls"] = redis[:calls].to_s
+          headers["X-Redis-Time"] = "%0.6f" % redis[:duration]
+        end
+        if sql = info[:sql]
+          headers["X-Sql-Calls"] = sql[:calls].to_s
+          headers["X-Sql-Time"] = "%0.6f" % sql[:duration]
+        end
+        if queue = env['REQUEST_QUEUE_SECONDS']
+          headers["X-Queue-Time"] = "%0.6f" % queue
+        end
+      end
     end
 
     if env[Auth::DefaultCurrentUserProvider::BAD_TOKEN] && (headers = result[1])
diff --git a/spec/components/middleware/request_tracker_spec.rb b/spec/components/middleware/request_tracker_spec.rb
index ca8e1b6..ae73bba 100644
--- a/spec/components/middleware/request_tracker_spec.rb
+++ b/spec/components/middleware/request_tracker_spec.rb
@@ -274,6 +274,8 @@ describe Middleware::RequestTracker do
 
     it "can correctly log detailed data" do
 
+      global_setting :enable_performance_http_headers, true
+
       # ensure pg is warmed up with the select 1 query
       User.where(id: -100).pluck(:id)
 
@@ -283,7 +285,7 @@ describe Middleware::RequestTracker do
       freeze_time 1.minute.from_now
 
       tracker = Middleware::RequestTracker.new(app([200, {}, []], sql_calls: 2, redis_calls: 2))
-      tracker.call(env("HTTP_X_REQUEST_START" => "t=#{start}"))
+      _, headers, _ = tracker.call(env("HTTP_X_REQUEST_START" => "t=#{start}"))
 
       expect(@data[:queue_seconds]).to eq(60)
 
@@ -295,6 +297,16 @@ describe Middleware::RequestTracker do
 
       expect(timing[:redis][:duration]).to be > 0
       expect(timing[:redis][:calls]).to eq 2
+
+      expect(headers["X-Queue-Time"]).to eq("60.000000")
+
+      expect(headers["X-Redis-Calls"]).to eq("2")
+      expect(headers["X-Redis-Time"].to_f).to be > 0
+
+      expect(headers["X-Sql-Calls"]).to eq("2")
+      expect(headers["X-Sql-Time"].to_f).to be > 0
+
+      expect(headers["X-Runtime"].to_f).to be > 0
     end
   end

GitHub sha: 62141b63

1 Like