485 lines
15 KiB
Ruby
485 lines
15 KiB
Ruby
# frozen_string_literal: true
|
|
|
|
require "rails_helper"
|
|
|
|
describe Middleware::RequestTracker do
|
|
|
|
def env(opts = {})
|
|
{
|
|
"HTTP_HOST" => "http://test.com",
|
|
"HTTP_USER_AGENT" => "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2228.0 Safari/537.36",
|
|
"REQUEST_URI" => "/path?bla=1",
|
|
"REQUEST_METHOD" => "GET",
|
|
"HTTP_ACCEPT" => "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8",
|
|
"rack.input" => ""
|
|
}.merge(opts)
|
|
end
|
|
|
|
before do
|
|
ApplicationRequest.clear_cache!
|
|
ApplicationRequest.enable
|
|
end
|
|
|
|
after do
|
|
ApplicationRequest.disable
|
|
ApplicationRequest.clear_cache!
|
|
end
|
|
|
|
context "full request" do
|
|
before do
|
|
@orig = WebCrawlerRequest.autoflush
|
|
WebCrawlerRequest.autoflush = 1
|
|
end
|
|
after do
|
|
WebCrawlerRequest.autoflush = @orig
|
|
end
|
|
|
|
it "can handle rogue user agents" do
|
|
agent = (+"Evil Googlebot String \xc3\x28").force_encoding("Windows-1252")
|
|
|
|
middleware = Middleware::RequestTracker.new(->(env) { ["200", { "Content-Type" => "text/html" }, [""]] })
|
|
middleware.call(env("HTTP_USER_AGENT" => agent))
|
|
|
|
expect(WebCrawlerRequest.where(user_agent: agent.encode('utf-8')).count).to eq(1)
|
|
end
|
|
|
|
end
|
|
|
|
context "log_request" do
|
|
before do
|
|
freeze_time Time.now
|
|
ApplicationRequest.clear_cache!
|
|
end
|
|
|
|
def log_tracked_view(val)
|
|
data = Middleware::RequestTracker.get_data(env(
|
|
"HTTP_DISCOURSE_TRACK_VIEW" => val
|
|
), ["200", { "Content-Type" => 'text/html' }], 0.2)
|
|
|
|
Middleware::RequestTracker.log_request(data)
|
|
end
|
|
|
|
it "can exclude/include based on custom header" do
|
|
log_tracked_view("true")
|
|
log_tracked_view("1")
|
|
log_tracked_view("false")
|
|
log_tracked_view("0")
|
|
ApplicationRequest.write_cache!
|
|
|
|
expect(ApplicationRequest.page_view_anon.first.count).to eq(2)
|
|
end
|
|
|
|
it "can log requests correctly" do
|
|
data = Middleware::RequestTracker.get_data(env(
|
|
"HTTP_USER_AGENT" => "AdsBot-Google (+http://www.google.com/adsbot.html)"
|
|
), ["200", { "Content-Type" => 'text/html' }], 0.1)
|
|
|
|
Middleware::RequestTracker.log_request(data)
|
|
|
|
data = Middleware::RequestTracker.get_data(env(
|
|
"HTTP_DISCOURSE_TRACK_VIEW" => "1"
|
|
), ["200", {}], 0.1)
|
|
|
|
Middleware::RequestTracker.log_request(data)
|
|
|
|
data = Middleware::RequestTracker.get_data(env(
|
|
"HTTP_USER_AGENT" => "Mozilla/5.0 (iPhone; CPU iPhone OS 8_1 like Mac OS X) AppleWebKit/600.1.4 (KHTML, like Gecko) Version/8.0 Mobile/12B410 Safari/600.1.4"
|
|
), ["200", { "Content-Type" => 'text/html' }], 0.1)
|
|
|
|
Middleware::RequestTracker.log_request(data)
|
|
|
|
# /srv/status is never a tracked view because content-type is text/plain
|
|
data = Middleware::RequestTracker.get_data(env(
|
|
"HTTP_USER_AGENT" => "kube-probe/1.18",
|
|
"REQUEST_URI" => "/srv/status?shutdown_ok=1",
|
|
), ["200", { "Content-Type" => 'text/plain' }], 0.1)
|
|
|
|
Middleware::RequestTracker.log_request(data)
|
|
|
|
ApplicationRequest.write_cache!
|
|
|
|
expect(ApplicationRequest.http_total.first.count).to eq(4)
|
|
expect(ApplicationRequest.http_2xx.first.count).to eq(4)
|
|
|
|
expect(ApplicationRequest.page_view_anon.first.count).to eq(2)
|
|
expect(ApplicationRequest.page_view_crawler.first.count).to eq(1)
|
|
expect(ApplicationRequest.page_view_anon_mobile.first.count).to eq(1)
|
|
|
|
expect(ApplicationRequest.page_view_crawler.first.count).to eq(1)
|
|
end
|
|
|
|
it "can log Discourse user agent requests correctly" do
|
|
# log discourse api agents as crawlers for page view stats...
|
|
data = Middleware::RequestTracker.get_data(env(
|
|
"HTTP_USER_AGENT" => "DiscourseAPI Ruby Gem 0.19.0"
|
|
), ["200", { "Content-Type" => 'text/html' }], 0.1)
|
|
|
|
Middleware::RequestTracker.log_request(data)
|
|
ApplicationRequest.write_cache!
|
|
expect(ApplicationRequest.page_view_crawler.first.count).to eq(1)
|
|
|
|
# ...but count our mobile app user agents as regular visits
|
|
data = Middleware::RequestTracker.get_data(env(
|
|
"HTTP_USER_AGENT" => "Mozilla/5.0 AppleWebKit/605.1.15 Mobile/15E148 DiscourseHub)"
|
|
), ["200", { "Content-Type" => 'text/html' }], 0.1)
|
|
|
|
Middleware::RequestTracker.log_request(data)
|
|
ApplicationRequest.write_cache!
|
|
|
|
expect(ApplicationRequest.page_view_crawler.first.count).to eq(1)
|
|
expect(ApplicationRequest.page_view_anon.first.count).to eq(1)
|
|
end
|
|
|
|
context "ignore_anonymous_pageviews" do
|
|
let(:anon_data) do
|
|
Middleware::RequestTracker.get_data(env(
|
|
"HTTP_USER_AGENT" => "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.72 Safari/537.36"
|
|
), ["200", { "Content-Type" => 'text/html' }], 0.1)
|
|
end
|
|
|
|
let(:logged_in_data) do
|
|
user = Fabricate(:user, active: true)
|
|
token = UserAuthToken.generate!(user_id: user.id)
|
|
Middleware::RequestTracker.get_data(env(
|
|
"HTTP_USER_AGENT" => "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.72 Safari/537.36",
|
|
"HTTP_COOKIE" => "_t=#{token.unhashed_auth_token};"
|
|
), ["200", { "Content-Type" => 'text/html' }], 0.1)
|
|
end
|
|
|
|
it "does not ignore anonymous requests for public sites" do
|
|
SiteSetting.login_required = false
|
|
|
|
Middleware::RequestTracker.log_request(anon_data)
|
|
Middleware::RequestTracker.log_request(logged_in_data)
|
|
|
|
ApplicationRequest.write_cache!
|
|
|
|
expect(ApplicationRequest.http_total.first.count).to eq(2)
|
|
expect(ApplicationRequest.http_2xx.first.count).to eq(2)
|
|
|
|
expect(ApplicationRequest.page_view_logged_in.first.count).to eq(1)
|
|
expect(ApplicationRequest.page_view_anon.first.count).to eq(1)
|
|
end
|
|
|
|
it "ignores anonymous requests for private sites" do
|
|
SiteSetting.login_required = true
|
|
|
|
Middleware::RequestTracker.log_request(anon_data)
|
|
Middleware::RequestTracker.log_request(logged_in_data)
|
|
|
|
ApplicationRequest.write_cache!
|
|
|
|
expect(ApplicationRequest.http_total.first.count).to eq(2)
|
|
expect(ApplicationRequest.http_2xx.first.count).to eq(2)
|
|
|
|
expect(ApplicationRequest.page_view_logged_in.first.count).to eq(1)
|
|
expect(ApplicationRequest.page_view_anon.first).to eq(nil)
|
|
end
|
|
end
|
|
end
|
|
|
|
context "rate limiting" do
|
|
|
|
class TestLogger
|
|
attr_accessor :warnings
|
|
|
|
def initialize
|
|
@warnings = 0
|
|
end
|
|
|
|
def warn(*args)
|
|
@warnings += 1
|
|
end
|
|
end
|
|
|
|
before do
|
|
RateLimiter.enable
|
|
RateLimiter.clear_all_global!
|
|
|
|
@old_logger = Rails.logger
|
|
Rails.logger = TestLogger.new
|
|
|
|
# rate limiter tests depend on checks for retry-after
|
|
# they can be sensitive to clock skew during test runs
|
|
freeze_time DateTime.parse('2021-01-01 01:00')
|
|
end
|
|
|
|
after do
|
|
Rails.logger = @old_logger
|
|
end
|
|
|
|
let :middleware do
|
|
app = lambda do |env|
|
|
[200, {}, ["OK"]]
|
|
end
|
|
|
|
Middleware::RequestTracker.new(app)
|
|
end
|
|
|
|
it "does nothing if configured to do nothing" do
|
|
global_setting :max_reqs_per_ip_mode, "none"
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
|
|
status, _ = middleware.call(env)
|
|
status, _ = middleware.call(env)
|
|
|
|
expect(status).to eq(200)
|
|
end
|
|
|
|
it "blocks private IPs if not skipped" do
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
global_setting :max_reqs_per_ip_mode, 'warn+block'
|
|
global_setting :max_reqs_rate_limit_on_private, true
|
|
|
|
addresses = %w[127.1.2.3 127.0.0.2 192.168.1.2 10.0.1.2 172.16.9.8 172.19.1.2 172.20.9.8 172.29.1.2 172.30.9.8 172.31.1.2]
|
|
warn_count = 1
|
|
addresses.each do |addr|
|
|
env1 = env("REMOTE_ADDR" => addr)
|
|
|
|
status, _ = middleware.call(env1)
|
|
status, _ = middleware.call(env1)
|
|
|
|
expect(Rails.logger.warnings).to eq(warn_count)
|
|
expect(status).to eq(429)
|
|
warn_count += 1
|
|
end
|
|
end
|
|
|
|
it "blocks if the ip isn't static skipped" do
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
global_setting :max_reqs_per_ip_mode, 'block'
|
|
|
|
env1 = env("REMOTE_ADDR" => "1.1.1.1")
|
|
status, _ = middleware.call(env1)
|
|
status, _ = middleware.call(env1)
|
|
expect(status).to eq(429)
|
|
end
|
|
|
|
it "doesn't block if rate limiter is enabled but IP is on the static exception list" do
|
|
stub_const(Middleware::RequestTracker, "STATIC_IP_SKIPPER", "177.33.14.73 191.209.88.192/30"&.split&.map { |ip| IPAddr.new(ip) }) do
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
global_setting :max_reqs_per_ip_mode, 'block'
|
|
|
|
env1 = env("REMOTE_ADDR" => "177.33.14.73")
|
|
env2 = env("REMOTE_ADDR" => "191.209.88.194")
|
|
|
|
status, _ = middleware.call(env1)
|
|
expect(status).to eq(200)
|
|
|
|
status, _ = middleware.call(env1)
|
|
expect(status).to eq(200)
|
|
|
|
status, _ = middleware.call(env2)
|
|
expect(status).to eq(200)
|
|
|
|
status, _ = middleware.call(env2)
|
|
expect(status).to eq(200)
|
|
end
|
|
end
|
|
|
|
describe "register_ip_skipper" do
|
|
before do
|
|
Middleware::RequestTracker.register_ip_skipper do |ip|
|
|
ip == "1.1.1.2"
|
|
end
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
global_setting :max_reqs_per_ip_mode, 'block'
|
|
end
|
|
|
|
after do
|
|
Middleware::RequestTracker.unregister_ip_skipper
|
|
end
|
|
|
|
it "won't block if the ip is skipped" do
|
|
env1 = env("REMOTE_ADDR" => "1.1.1.2")
|
|
status, _ = middleware.call(env1)
|
|
status, _ = middleware.call(env1)
|
|
expect(status).to eq(200)
|
|
end
|
|
|
|
it "blocks if the ip isn't skipped" do
|
|
env1 = env("REMOTE_ADDR" => "1.1.1.1")
|
|
status, _ = middleware.call(env1)
|
|
status, _ = middleware.call(env1)
|
|
expect(status).to eq(429)
|
|
end
|
|
end
|
|
|
|
it "does nothing for private IPs if skipped" do
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
global_setting :max_reqs_per_ip_mode, 'warn+block'
|
|
global_setting :max_reqs_rate_limit_on_private, false
|
|
|
|
addresses = %w[127.1.2.3 127.0.3.1 192.168.1.2 10.0.1.2 172.16.9.8 172.19.1.2 172.20.9.8 172.29.1.2 172.30.9.8 172.31.1.2]
|
|
addresses.each do |addr|
|
|
env1 = env("REMOTE_ADDR" => addr)
|
|
|
|
status, _ = middleware.call(env1)
|
|
status, _ = middleware.call(env1)
|
|
|
|
expect(Rails.logger.warnings).to eq(0)
|
|
expect(status).to eq(200)
|
|
end
|
|
end
|
|
|
|
it "does warn if rate limiter is enabled via warn+block" do
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
global_setting :max_reqs_per_ip_mode, 'warn+block'
|
|
|
|
status, _ = middleware.call(env)
|
|
status, headers = middleware.call(env)
|
|
|
|
expect(Rails.logger.warnings).to eq(1)
|
|
expect(status).to eq(429)
|
|
expect(headers["Retry-After"]).to eq("10")
|
|
end
|
|
|
|
it "does warn if rate limiter is enabled" do
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
global_setting :max_reqs_per_ip_mode, 'warn'
|
|
|
|
status, _ = middleware.call(env)
|
|
status, _ = middleware.call(env)
|
|
|
|
expect(Rails.logger.warnings).to eq(1)
|
|
expect(status).to eq(200)
|
|
end
|
|
|
|
it "allows assets for more requests" do
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
global_setting :max_reqs_per_ip_mode, 'block'
|
|
global_setting :max_asset_reqs_per_ip_per_10_seconds, 3
|
|
|
|
env1 = env("REMOTE_ADDR" => "1.1.1.1", "DISCOURSE_IS_ASSET_PATH" => 1)
|
|
|
|
status, _ = middleware.call(env1)
|
|
expect(status).to eq(200)
|
|
status, _ = middleware.call(env1)
|
|
expect(status).to eq(200)
|
|
status, _ = middleware.call(env1)
|
|
expect(status).to eq(200)
|
|
status, headers = middleware.call(env1)
|
|
expect(status).to eq(429)
|
|
expect(headers["Retry-After"]).to eq("10")
|
|
|
|
env2 = env("REMOTE_ADDR" => "1.1.1.1")
|
|
|
|
status, headers = middleware.call(env2)
|
|
expect(status).to eq(429)
|
|
expect(headers["Retry-After"]).to eq("10")
|
|
end
|
|
|
|
it "does block if rate limiter is enabled" do
|
|
global_setting :max_reqs_per_ip_per_10_seconds, 1
|
|
global_setting :max_reqs_per_ip_mode, 'block'
|
|
|
|
env1 = env("REMOTE_ADDR" => "1.1.1.1")
|
|
env2 = env("REMOTE_ADDR" => "1.1.1.2")
|
|
|
|
status, _ = middleware.call(env1)
|
|
expect(status).to eq(200)
|
|
|
|
status, headers = middleware.call(env1)
|
|
expect(status).to eq(429)
|
|
expect(headers["Retry-After"]).to eq("10")
|
|
|
|
status, _ = middleware.call(env2)
|
|
expect(status).to eq(200)
|
|
end
|
|
end
|
|
|
|
context "callbacks" do
|
|
def app(result, sql_calls: 0, redis_calls: 0)
|
|
lambda do |env|
|
|
sql_calls.times do
|
|
User.where(id: -100).pluck(:id)
|
|
end
|
|
redis_calls.times do
|
|
Discourse.redis.get("x")
|
|
end
|
|
result
|
|
end
|
|
end
|
|
|
|
let :logger do
|
|
->(env, data) do
|
|
@env = env
|
|
@data = data
|
|
end
|
|
end
|
|
|
|
before do
|
|
Middleware::RequestTracker.register_detailed_request_logger(logger)
|
|
end
|
|
|
|
after do
|
|
Middleware::RequestTracker.unregister_detailed_request_logger(logger)
|
|
end
|
|
|
|
it "can report data from anon cache" do
|
|
cache = Middleware::AnonymousCache.new(app([200, {}, ["i am a thing"]]))
|
|
tracker = Middleware::RequestTracker.new(cache)
|
|
|
|
uri = "/path?#{SecureRandom.hex}"
|
|
|
|
request_params = {
|
|
"a" => "b",
|
|
"action" => "bob",
|
|
"controller" => "jane"
|
|
}
|
|
|
|
tracker.call(env("REQUEST_URI" => uri, "ANON_CACHE_DURATION" => 60, "action_dispatch.request.parameters" => request_params))
|
|
expect(@data[:cache]).to eq("skip")
|
|
|
|
tracker.call(env("REQUEST_URI" => uri, "ANON_CACHE_DURATION" => 60, "action_dispatch.request.parameters" => request_params))
|
|
expect(@data[:cache]).to eq("store")
|
|
|
|
tracker.call(env("REQUEST_URI" => uri, "ANON_CACHE_DURATION" => 60))
|
|
expect(@data[:cache]).to eq("true")
|
|
|
|
# not allowlisted
|
|
request_params.delete("a")
|
|
|
|
expect(@env["action_dispatch.request.parameters"]).to eq(request_params)
|
|
end
|
|
|
|
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)
|
|
|
|
freeze_time
|
|
start = Time.now.to_f
|
|
|
|
freeze_time 1.minute.from_now
|
|
|
|
tracker = Middleware::RequestTracker.new(app([200, {}, []], sql_calls: 2, redis_calls: 2))
|
|
_, headers, _ = tracker.call(env("HTTP_X_REQUEST_START" => "t=#{start}"))
|
|
|
|
expect(@data[:queue_seconds]).to eq(60)
|
|
|
|
timing = @data[:timing]
|
|
expect(timing[:total_duration]).to be > 0
|
|
|
|
expect(timing[:sql][:duration]).to be > 0
|
|
expect(timing[:sql][:calls]).to eq 2
|
|
|
|
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
|
|
|
|
end
|