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

```text
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
This commit is contained in:
Sam Saffron 2019-06-05 16:08:11 +10:00
parent 6d8eb9c144
commit 62141b6316
4 changed files with 41 additions and 1 deletions

View File

@ -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

View File

@ -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

View File

@ -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])

View File

@ -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