2017-10-17 21:10:12 -04:00
|
|
|
# frozen_string_literal: true
|
|
|
|
|
2018-12-30 18:53:30 -05:00
|
|
|
require 'method_profiler'
|
|
|
|
require 'middleware/anonymous_cache'
|
2015-02-05 00:08:52 -05:00
|
|
|
|
|
|
|
class Middleware::RequestTracker
|
|
|
|
|
2017-10-17 21:10:12 -04:00
|
|
|
@@detailed_request_loggers = nil
|
2018-02-05 17:45:25 -05:00
|
|
|
@@ip_skipper = nil
|
2017-10-17 21:10:12 -04:00
|
|
|
|
2021-08-13 11:00:23 -04:00
|
|
|
# You can add exceptions to our app rate limiter in the app.yml ENV section.
|
|
|
|
# example:
|
|
|
|
#
|
|
|
|
# env:
|
|
|
|
# DISCOURSE_MAX_REQS_PER_IP_EXCEPTIONS: >-
|
|
|
|
# 14.15.16.32/27
|
|
|
|
# 216.148.1.2
|
|
|
|
#
|
|
|
|
STATIC_IP_SKIPPER = ENV['DISCOURSE_MAX_REQS_PER_IP_EXCEPTIONS']&.split&.map { |ip| IPAddr.new(ip) }
|
|
|
|
|
2017-10-17 21:10:12 -04:00
|
|
|
# register callbacks for detailed request loggers called on every request
|
|
|
|
# example:
|
|
|
|
#
|
|
|
|
# Middleware::RequestTracker.detailed_request_logger(->|env, data| do
|
|
|
|
# # do stuff with env and data
|
|
|
|
# end
|
|
|
|
def self.register_detailed_request_logger(callback)
|
2019-03-05 06:19:11 -05:00
|
|
|
MethodProfiler.ensure_discourse_instrumentation!
|
2017-10-17 21:10:12 -04:00
|
|
|
(@@detailed_request_loggers ||= []) << callback
|
|
|
|
end
|
|
|
|
|
|
|
|
def self.unregister_detailed_request_logger(callback)
|
2021-01-19 04:35:46 -05:00
|
|
|
@@detailed_request_loggers.delete(callback)
|
2017-10-17 21:10:12 -04:00
|
|
|
if @@detailed_request_loggers.length == 0
|
|
|
|
@detailed_request_loggers = nil
|
|
|
|
end
|
2018-02-05 17:45:25 -05:00
|
|
|
end
|
2017-10-17 21:10:12 -04:00
|
|
|
|
2018-02-05 18:38:15 -05:00
|
|
|
# used for testing
|
|
|
|
def self.unregister_ip_skipper
|
|
|
|
@@ip_skipper = nil
|
|
|
|
end
|
|
|
|
|
2018-02-05 17:45:25 -05:00
|
|
|
# Register a custom `ip_skipper`, a function that will skip rate limiting
|
|
|
|
# for any IP that returns true.
|
|
|
|
#
|
|
|
|
# For example, if you never wanted to rate limit 1.2.3.4
|
|
|
|
#
|
|
|
|
# ```
|
|
|
|
# Middleware::RequestTracker.register_ip_skipper do |ip|
|
|
|
|
# ip == "1.2.3.4"
|
|
|
|
# end
|
|
|
|
# ```
|
|
|
|
def self.register_ip_skipper(&blk)
|
2018-02-05 18:38:15 -05:00
|
|
|
raise "IP skipper is already registered!" if @@ip_skipper
|
2018-02-05 17:45:25 -05:00
|
|
|
@@ip_skipper = blk
|
2017-10-17 21:10:12 -04:00
|
|
|
end
|
|
|
|
|
2015-02-05 00:08:52 -05:00
|
|
|
def initialize(app, settings = {})
|
|
|
|
@app = app
|
|
|
|
end
|
|
|
|
|
2015-02-10 01:03:33 -05:00
|
|
|
def self.log_request(data)
|
|
|
|
status = data[:status]
|
|
|
|
track_view = data[:track_view]
|
2015-02-05 00:08:52 -05:00
|
|
|
|
2015-02-10 01:03:33 -05:00
|
|
|
if track_view
|
|
|
|
if data[:is_crawler]
|
2015-02-05 22:39:04 -05:00
|
|
|
ApplicationRequest.increment!(:page_view_crawler)
|
2018-03-15 17:10:45 -04:00
|
|
|
WebCrawlerRequest.increment!(data[:user_agent])
|
2015-02-10 01:03:33 -05:00
|
|
|
elsif data[:has_auth_cookie]
|
2015-02-05 22:39:04 -05:00
|
|
|
ApplicationRequest.increment!(:page_view_logged_in)
|
2015-07-03 17:02:57 -04:00
|
|
|
ApplicationRequest.increment!(:page_view_logged_in_mobile) if data[:is_mobile]
|
2021-04-26 07:19:47 -04:00
|
|
|
elsif !SiteSetting.login_required
|
2015-02-05 22:39:04 -05:00
|
|
|
ApplicationRequest.increment!(:page_view_anon)
|
2015-07-03 17:02:57 -04:00
|
|
|
ApplicationRequest.increment!(:page_view_anon_mobile) if data[:is_mobile]
|
2015-02-05 22:39:04 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
ApplicationRequest.increment!(:http_total)
|
|
|
|
|
|
|
|
if status >= 500
|
|
|
|
ApplicationRequest.increment!(:http_5xx)
|
2015-02-11 17:47:32 -05:00
|
|
|
elsif data[:is_background]
|
|
|
|
ApplicationRequest.increment!(:http_background)
|
2015-02-05 22:39:04 -05:00
|
|
|
elsif status >= 400
|
|
|
|
ApplicationRequest.increment!(:http_4xx)
|
|
|
|
elsif status >= 300
|
|
|
|
ApplicationRequest.increment!(:http_3xx)
|
2021-01-19 04:35:46 -05:00
|
|
|
elsif status >= 200
|
2015-02-11 17:47:32 -05:00
|
|
|
ApplicationRequest.increment!(:http_2xx)
|
2015-02-05 00:08:52 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2017-10-17 21:10:12 -04:00
|
|
|
def self.get_data(env, result, timing)
|
2015-02-10 01:03:33 -05:00
|
|
|
status, headers = result
|
|
|
|
status = status.to_i
|
|
|
|
|
|
|
|
helper = Middleware::AnonymousCache::Helper.new(env)
|
|
|
|
request = Rack::Request.new(env)
|
2015-02-25 19:40:57 -05:00
|
|
|
|
2017-10-17 21:10:12 -04:00
|
|
|
env_track_view = env["HTTP_DISCOURSE_TRACK_VIEW"]
|
2015-02-25 19:40:57 -05:00
|
|
|
track_view = status == 200
|
2017-10-17 21:10:12 -04:00
|
|
|
track_view &&= env_track_view != "0" && env_track_view != "false"
|
|
|
|
track_view &&= env_track_view || (request.get? && !request.xhr? && headers["Content-Type"] =~ /text\/html/)
|
2015-09-16 21:06:21 -04:00
|
|
|
track_view = !!track_view
|
2015-02-25 19:40:57 -05:00
|
|
|
|
2019-09-02 04:45:35 -04:00
|
|
|
h = {
|
2015-02-10 01:03:33 -05:00
|
|
|
status: status,
|
|
|
|
is_crawler: helper.is_crawler?,
|
|
|
|
has_auth_cookie: helper.has_auth_cookie?,
|
2018-01-18 18:37:27 -05:00
|
|
|
is_background: !!(request.path =~ /^\/message-bus\// || request.path =~ /\/topics\/timings/),
|
2015-07-03 17:02:57 -04:00
|
|
|
is_mobile: helper.is_mobile?,
|
2017-10-17 21:10:12 -04:00
|
|
|
track_view: track_view,
|
2018-04-17 04:05:51 -04:00
|
|
|
timing: timing,
|
|
|
|
queue_seconds: env['REQUEST_QUEUE_SECONDS']
|
2019-09-02 04:45:35 -04:00
|
|
|
}
|
|
|
|
|
|
|
|
if h[:is_crawler]
|
2019-12-09 01:43:51 -05:00
|
|
|
user_agent = env['HTTP_USER_AGENT']
|
2019-12-09 02:40:10 -05:00
|
|
|
if user_agent && (user_agent.encoding != Encoding::UTF_8)
|
2019-12-09 01:43:51 -05:00
|
|
|
user_agent = user_agent.encode("utf-8")
|
|
|
|
user_agent.scrub!
|
|
|
|
end
|
|
|
|
h[:user_agent] = user_agent
|
2019-09-02 04:45:35 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
if cache = headers["X-Discourse-Cached"]
|
|
|
|
h[:cache] = cache
|
2018-03-15 17:10:45 -04:00
|
|
|
end
|
2021-01-19 04:35:46 -05:00
|
|
|
|
2019-09-02 04:45:35 -04:00
|
|
|
h
|
2015-02-10 01:03:33 -05:00
|
|
|
end
|
2015-02-05 00:08:52 -05:00
|
|
|
|
2017-11-28 00:47:20 -05:00
|
|
|
def log_request_info(env, result, info)
|
2015-02-10 01:03:33 -05:00
|
|
|
# we got to skip this on error ... its just logging
|
2017-10-17 21:10:12 -04:00
|
|
|
data = self.class.get_data(env, result, info) rescue nil
|
2015-02-10 01:03:33 -05:00
|
|
|
|
|
|
|
if data
|
2016-10-27 01:50:56 -04:00
|
|
|
if result && (headers = result[1])
|
2016-10-27 03:08:01 -04:00
|
|
|
headers["X-Discourse-TrackView"] = "1" if data[:track_view]
|
2016-10-27 01:50:56 -04:00
|
|
|
end
|
2017-10-17 21:10:12 -04:00
|
|
|
|
|
|
|
if @@detailed_request_loggers
|
|
|
|
@@detailed_request_loggers.each { |logger| logger.call(env, data) }
|
|
|
|
end
|
|
|
|
|
2020-03-30 07:01:06 -04:00
|
|
|
log_later(data)
|
2015-02-05 00:08:52 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2019-08-09 03:47:44 -04:00
|
|
|
def self.populate_request_queue_seconds!(env)
|
|
|
|
if !env['REQUEST_QUEUE_SECONDS']
|
|
|
|
if queue_start = env['HTTP_X_REQUEST_START']
|
2020-06-19 10:17:24 -04:00
|
|
|
queue_start = if queue_start.start_with?("t=")
|
|
|
|
queue_start.split("t=")[1].to_f
|
|
|
|
else
|
|
|
|
queue_start.to_f / 1000.0
|
|
|
|
end
|
2019-08-09 03:47:44 -04:00
|
|
|
queue_time = (Time.now.to_f - queue_start)
|
|
|
|
env['REQUEST_QUEUE_SECONDS'] = queue_time
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2017-11-28 00:47:20 -05:00
|
|
|
def call(env)
|
2017-12-11 01:21:00 -05:00
|
|
|
result = nil
|
2018-03-15 17:10:45 -04:00
|
|
|
log_request = true
|
2018-04-17 04:05:51 -04:00
|
|
|
|
|
|
|
# doing this as early as possible so we have an
|
|
|
|
# accurate counter
|
2019-08-09 03:47:44 -04:00
|
|
|
::Middleware::RequestTracker.populate_request_queue_seconds!(env)
|
2018-04-17 04:05:51 -04:00
|
|
|
|
2018-03-15 17:10:45 -04:00
|
|
|
request = Rack::Request.new(env)
|
2017-12-11 01:21:00 -05:00
|
|
|
|
2021-01-19 04:35:46 -05:00
|
|
|
if available_in = rate_limit(request)
|
|
|
|
return [
|
|
|
|
429,
|
2021-03-23 15:32:36 -04:00
|
|
|
{ "Retry-After" => available_in.to_s },
|
2021-01-19 04:35:46 -05:00
|
|
|
["Slow down, too many requests from this IP address"]
|
|
|
|
]
|
2017-12-11 01:21:00 -05:00
|
|
|
end
|
|
|
|
|
2017-11-28 00:47:20 -05:00
|
|
|
env["discourse.request_tracker"] = self
|
2021-01-19 04:35:46 -05:00
|
|
|
|
2018-01-18 16:26:18 -05:00
|
|
|
MethodProfiler.start
|
2017-11-28 00:47:20 -05:00
|
|
|
result = @app.call(env)
|
2018-01-18 16:26:18 -05:00
|
|
|
info = MethodProfiler.stop
|
2021-01-19 04:35:46 -05:00
|
|
|
|
2018-01-18 16:26:18 -05:00
|
|
|
# possibly transferred?
|
2018-01-19 01:51:04 -05:00
|
|
|
if info && (headers = result[1])
|
|
|
|
headers["X-Runtime"] = "%0.6f" % info[:total_duration]
|
2019-06-05 02:08:11 -04:00
|
|
|
|
|
|
|
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
|
2018-01-18 16:26:18 -05:00
|
|
|
end
|
2018-03-06 00:49:31 -05:00
|
|
|
|
|
|
|
if env[Auth::DefaultCurrentUserProvider::BAD_TOKEN] && (headers = result[1])
|
|
|
|
headers['Discourse-Logged-Out'] = '1'
|
|
|
|
end
|
|
|
|
|
2017-11-28 00:47:20 -05:00
|
|
|
result
|
|
|
|
ensure
|
2018-03-05 23:20:39 -05:00
|
|
|
if (limiters = env['DISCOURSE_RATE_LIMITERS']) && env['DISCOURSE_IS_ASSET_PATH']
|
|
|
|
limiters.each(&:rollback!)
|
|
|
|
env['DISCOURSE_ASSET_RATE_LIMITERS'].each do |limiter|
|
|
|
|
begin
|
|
|
|
limiter.performed!
|
|
|
|
rescue RateLimiter::LimitExceeded
|
|
|
|
# skip
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
2018-03-15 17:10:45 -04:00
|
|
|
log_request_info(env, result, info) unless !log_request || env["discourse.request_tracker.skip"]
|
2017-11-28 00:47:20 -05:00
|
|
|
end
|
|
|
|
|
2018-01-07 16:39:17 -05:00
|
|
|
def is_private_ip?(ip)
|
|
|
|
ip = IPAddr.new(ip) rescue nil
|
2021-03-21 23:56:32 -04:00
|
|
|
!!(ip && (ip.private? || ip.loopback?))
|
2018-01-07 16:39:17 -05:00
|
|
|
end
|
|
|
|
|
2018-03-15 17:10:45 -04:00
|
|
|
def rate_limit(request)
|
2017-12-11 01:21:00 -05:00
|
|
|
if (
|
2018-01-21 21:18:30 -05:00
|
|
|
GlobalSetting.max_reqs_per_ip_mode == "block" ||
|
|
|
|
GlobalSetting.max_reqs_per_ip_mode == "warn" ||
|
|
|
|
GlobalSetting.max_reqs_per_ip_mode == "warn+block"
|
2017-12-11 01:21:00 -05:00
|
|
|
)
|
|
|
|
|
2018-03-15 17:10:45 -04:00
|
|
|
ip = request.ip
|
2017-12-11 01:21:00 -05:00
|
|
|
|
2018-01-21 21:18:30 -05:00
|
|
|
if !GlobalSetting.max_reqs_rate_limit_on_private
|
2018-01-07 16:39:17 -05:00
|
|
|
return false if is_private_ip?(ip)
|
|
|
|
end
|
|
|
|
|
2018-02-05 18:38:15 -05:00
|
|
|
return false if @@ip_skipper&.call(ip)
|
2021-08-13 11:00:23 -04:00
|
|
|
return false if STATIC_IP_SKIPPER&.any? { |entry| entry.include?(ip) }
|
2018-02-05 17:45:25 -05:00
|
|
|
|
2017-12-11 01:21:00 -05:00
|
|
|
limiter10 = RateLimiter.new(
|
|
|
|
nil,
|
|
|
|
"global_ip_limit_10_#{ip}",
|
2018-01-21 21:18:30 -05:00
|
|
|
GlobalSetting.max_reqs_per_ip_per_10_seconds,
|
2017-12-11 01:21:00 -05:00
|
|
|
10,
|
2020-11-05 00:36:17 -05:00
|
|
|
global: true,
|
|
|
|
aggressive: true
|
2017-12-11 01:21:00 -05:00
|
|
|
)
|
|
|
|
|
|
|
|
limiter60 = RateLimiter.new(
|
|
|
|
nil,
|
|
|
|
"global_ip_limit_60_#{ip}",
|
2019-09-20 04:21:37 -04:00
|
|
|
GlobalSetting.max_reqs_per_ip_per_minute,
|
|
|
|
60,
|
2020-11-05 00:36:17 -05:00
|
|
|
global: true,
|
|
|
|
aggressive: true
|
2017-12-11 01:21:00 -05:00
|
|
|
)
|
|
|
|
|
2018-03-05 23:20:39 -05:00
|
|
|
limiter_assets10 = RateLimiter.new(
|
|
|
|
nil,
|
|
|
|
"global_ip_limit_10_assets_#{ip}",
|
|
|
|
GlobalSetting.max_asset_reqs_per_ip_per_10_seconds,
|
|
|
|
10,
|
|
|
|
global: true
|
|
|
|
)
|
|
|
|
|
2018-03-15 17:10:45 -04:00
|
|
|
request.env['DISCOURSE_RATE_LIMITERS'] = [limiter10, limiter60]
|
|
|
|
request.env['DISCOURSE_ASSET_RATE_LIMITERS'] = [limiter_assets10]
|
2018-03-05 23:20:39 -05:00
|
|
|
|
2021-01-19 04:35:46 -05:00
|
|
|
warn = GlobalSetting.max_reqs_per_ip_mode == "warn" || GlobalSetting.max_reqs_per_ip_mode == "warn+block"
|
2018-03-05 23:20:39 -05:00
|
|
|
|
|
|
|
if !limiter_assets10.can_perform?
|
|
|
|
if warn
|
2018-08-12 23:14:34 -04:00
|
|
|
Discourse.warn("Global asset IP rate limit exceeded for #{ip}: 10 second rate limit", uri: request.env["REQUEST_URI"])
|
2018-03-05 23:20:39 -05:00
|
|
|
end
|
|
|
|
|
2021-01-19 04:35:46 -05:00
|
|
|
if GlobalSetting.max_reqs_per_ip_mode != "warn"
|
|
|
|
return limiter_assets10.seconds_to_wait(Time.now.to_i)
|
|
|
|
else
|
|
|
|
return false
|
|
|
|
end
|
2018-03-05 23:20:39 -05:00
|
|
|
end
|
|
|
|
|
2017-12-11 01:21:00 -05:00
|
|
|
begin
|
2021-01-19 04:35:46 -05:00
|
|
|
type = 10
|
2017-12-11 01:21:00 -05:00
|
|
|
limiter10.performed!
|
2021-01-19 04:35:46 -05:00
|
|
|
|
2017-12-11 01:21:00 -05:00
|
|
|
type = 60
|
|
|
|
limiter60.performed!
|
2021-01-19 04:35:46 -05:00
|
|
|
|
2018-04-18 07:04:08 -04:00
|
|
|
false
|
2021-01-19 04:35:46 -05:00
|
|
|
rescue RateLimiter::LimitExceeded => e
|
2018-03-05 23:20:39 -05:00
|
|
|
if warn
|
2018-08-12 23:14:34 -04:00
|
|
|
Discourse.warn("Global IP rate limit exceeded for #{ip}: #{type} second rate limit", uri: request.env["REQUEST_URI"])
|
2021-01-19 04:35:46 -05:00
|
|
|
if GlobalSetting.max_reqs_per_ip_mode != "warn"
|
|
|
|
e.available_in
|
|
|
|
else
|
|
|
|
false
|
|
|
|
end
|
2017-12-11 01:21:00 -05:00
|
|
|
else
|
2021-01-19 04:35:46 -05:00
|
|
|
e.available_in
|
2017-12-11 01:21:00 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2020-03-30 07:01:06 -04:00
|
|
|
def log_later(data)
|
|
|
|
Scheduler::Defer.later("Track view") do
|
|
|
|
unless Discourse.pg_readonly_mode?
|
|
|
|
self.class.log_request(data)
|
|
|
|
end
|
2015-09-16 21:06:21 -04:00
|
|
|
end
|
|
|
|
end
|
2015-02-05 00:08:52 -05:00
|
|
|
end
|