PERF: perform all cached counting in background (#15991)
Previously cached counting made redis calls in main thread and performed the flush in main thread. This could lead to pathological states in extreme heavy load. This refactor reduces load and cleans up the interface
This commit is contained in:
parent
98a7fa3d1a
commit
d4d3580761
|
@ -23,50 +23,16 @@ class ApplicationRequest < ActiveRecord::Base
|
|||
@disabled = false
|
||||
end
|
||||
|
||||
def self.increment!(type, opts = nil)
|
||||
def self.increment!(req_type)
|
||||
return if @disabled
|
||||
perform_increment!(redis_key(type), opts)
|
||||
perform_increment!(req_type)
|
||||
end
|
||||
|
||||
def self.write_cache!(date = nil)
|
||||
if date.nil?
|
||||
write_cache!(Time.now.utc)
|
||||
write_cache!(Time.now.utc.yesterday)
|
||||
return
|
||||
end
|
||||
|
||||
self.last_flush = Time.now.utc
|
||||
|
||||
date = date.to_date
|
||||
|
||||
req_types.each do |req_type, _|
|
||||
val = get_and_reset(redis_key(req_type, date))
|
||||
|
||||
next if val == 0
|
||||
|
||||
id = req_id(date, req_type)
|
||||
where(id: id).update_all(["count = count + ?", val])
|
||||
end
|
||||
rescue Redis::CommandError => e
|
||||
raise unless e.message =~ /READONLY/
|
||||
nil
|
||||
def self.write_cache!(req_type, count, date)
|
||||
id = req_id(date, req_type)
|
||||
where(id: id).update_all(["count = count + ?", count])
|
||||
end
|
||||
|
||||
def self.clear_cache!(date = nil)
|
||||
if date.nil?
|
||||
clear_cache!(Time.now.utc)
|
||||
clear_cache!(Time.now.utc.yesterday)
|
||||
return
|
||||
end
|
||||
|
||||
req_types.each do |req_type, _|
|
||||
key = redis_key(req_type, date)
|
||||
Discourse.redis.del key
|
||||
end
|
||||
end
|
||||
|
||||
protected
|
||||
|
||||
def self.req_id(date, req_type, retries = 0)
|
||||
|
||||
req_type_id = req_types[req_type]
|
||||
|
@ -83,10 +49,6 @@ class ApplicationRequest < ActiveRecord::Base
|
|||
end
|
||||
end
|
||||
|
||||
def self.redis_key(req_type, time = Time.now.utc)
|
||||
"app_req_#{req_type}#{time.strftime('%Y%m%d')}"
|
||||
end
|
||||
|
||||
def self.stats
|
||||
s = HashWithIndifferentAccess.new({})
|
||||
|
||||
|
|
|
@ -3,75 +3,179 @@
|
|||
module CachedCounting
|
||||
extend ActiveSupport::Concern
|
||||
|
||||
EXPIRE_CACHE_AFTER = 4.days.to_i
|
||||
|
||||
LUA_INCR_AND_EXPIRE = DiscourseRedis::EvalHelper.new <<~LUA
|
||||
local result = redis.call("INCR", KEYS[1])
|
||||
|
||||
if result == 1 then
|
||||
redis.call("EXPIRE", KEYS[1], ARGV[1])
|
||||
end
|
||||
LUA_HGET_DEL = DiscourseRedis::EvalHelper.new <<~LUA
|
||||
local result = redis.call("HGET", KEYS[1], KEYS[2])
|
||||
redis.call("HDEL", KEYS[1], KEYS[2])
|
||||
|
||||
return result
|
||||
LUA
|
||||
|
||||
included do
|
||||
class << self
|
||||
attr_accessor :autoflush, :autoflush_seconds, :last_flush
|
||||
QUEUE = Queue.new
|
||||
SLEEP_SECONDS = 1
|
||||
FLUSH_DB_ITERATIONS = 60
|
||||
MUTEX = Mutex.new
|
||||
|
||||
def self.disable
|
||||
@enabled = false
|
||||
if @thread && @thread.alive?
|
||||
@thread.wakeup
|
||||
@thread.join
|
||||
end
|
||||
|
||||
# auto flush if backlog is larger than this
|
||||
self.autoflush = 2000
|
||||
|
||||
# auto flush if older than this
|
||||
self.autoflush_seconds = 5.minutes
|
||||
|
||||
self.last_flush = Time.now.utc
|
||||
end
|
||||
|
||||
class_methods do
|
||||
def perform_increment!(key, opts = nil)
|
||||
val = DiscourseRedis.ignore_readonly do
|
||||
LUA_INCR_AND_EXPIRE.eval(
|
||||
Discourse.redis.without_namespace,
|
||||
[Discourse.redis.namespace_key(key)],
|
||||
[EXPIRE_CACHE_AFTER]
|
||||
).to_i
|
||||
end
|
||||
def self.enabled?
|
||||
@enabled != false
|
||||
end
|
||||
|
||||
# readonly mode it is going to be nil, skip
|
||||
return if val.nil?
|
||||
def self.enable
|
||||
@enabled = true
|
||||
end
|
||||
|
||||
autoflush = (opts && opts[:autoflush]) || self.autoflush
|
||||
if autoflush > 0 && val >= autoflush
|
||||
write_cache!
|
||||
def self.reset
|
||||
@last_ensure_thread = nil
|
||||
clear_queue!
|
||||
clear_flush_to_db_lock!
|
||||
end
|
||||
|
||||
ENSURE_THREAD_COOLDOWN_SECONDS = 5
|
||||
|
||||
def self.ensure_thread!
|
||||
return if !enabled?
|
||||
|
||||
MUTEX.synchronize do
|
||||
now = Process.clock_gettime(Process::CLOCK_MONOTONIC)
|
||||
delta = @last_ensure_thread && (now - @last_ensure_thread)
|
||||
|
||||
if delta && delta < ENSURE_THREAD_COOLDOWN_SECONDS
|
||||
# creating threads can be very expensive and bog down a process
|
||||
return
|
||||
end
|
||||
|
||||
if (Time.now.utc - last_flush).to_i > autoflush_seconds
|
||||
write_cache!
|
||||
@last_ensure_thread = now
|
||||
|
||||
if !@thread&.alive?
|
||||
@thread = nil
|
||||
end
|
||||
@thread ||= Thread.new { thread_loop }
|
||||
end
|
||||
end
|
||||
|
||||
def self.thread_loop
|
||||
iterations = 0
|
||||
while true
|
||||
break if !enabled?
|
||||
|
||||
sleep SLEEP_SECONDS
|
||||
flush_in_memory
|
||||
if (iterations >= FLUSH_DB_ITERATIONS) || @flush
|
||||
iterations = 0
|
||||
flush_to_db
|
||||
@flush = false
|
||||
end
|
||||
iterations += 1
|
||||
end
|
||||
|
||||
def write_cache!(date = nil)
|
||||
raise NotImplementedError
|
||||
rescue => ex
|
||||
if Redis::CommandError === ex && ex.message =~ /READONLY/
|
||||
# do not warn for Redis readonly mode
|
||||
elsif PG::ReadOnlySqlTransaction === ex
|
||||
# do not warn for PG readonly mode
|
||||
else
|
||||
Discourse.warn_exception(
|
||||
ex,
|
||||
message: 'Unexpected error while processing cached counts'
|
||||
)
|
||||
end
|
||||
end
|
||||
|
||||
def self.flush
|
||||
@flush = true
|
||||
@thread.wakeup
|
||||
while @flush
|
||||
sleep 0.001
|
||||
end
|
||||
end
|
||||
|
||||
COUNTER_REDIS_HASH = "CounterCacheHash"
|
||||
|
||||
def self.flush_in_memory
|
||||
counts = nil
|
||||
while QUEUE.length > 0
|
||||
# only 1 consumer, no need to avoid blocking
|
||||
key, klass, db, time = QUEUE.deq
|
||||
_redis_key = "#{klass},#{db},#{time.strftime("%Y%m%d")},#{key}"
|
||||
counts ||= Hash.new(0)
|
||||
counts[_redis_key] += 1
|
||||
end
|
||||
|
||||
# this may seem a bit fancy but in so it allows
|
||||
# for concurrent calls without double counting
|
||||
def get_and_reset(key)
|
||||
Discourse.redis.set(key, '0', ex: EXPIRE_CACHE_AFTER, get: true).to_i
|
||||
end
|
||||
|
||||
def request_id(query_params, retries = 0)
|
||||
id = where(query_params).pluck_first(:id)
|
||||
id ||= create!(query_params.merge(count: 0)).id
|
||||
rescue # primary key violation
|
||||
if retries == 0
|
||||
request_id(query_params, 1)
|
||||
else
|
||||
raise
|
||||
if counts
|
||||
counts.each do |redis_key, count|
|
||||
Discourse.redis.without_namespace.hincrby(COUNTER_REDIS_HASH, redis_key, count)
|
||||
end
|
||||
end
|
||||
end
|
||||
|
||||
DB_FLUSH_COOLDOWN_SECONDS = 60
|
||||
DB_COOLDOWN_KEY = "cached_counting_cooldown"
|
||||
|
||||
def self.flush_to_db
|
||||
redis = Discourse.redis.without_namespace
|
||||
DistributedMutex.synchronize("flush_counters_to_db", redis: redis, validity: 5.minutes) do
|
||||
if allowed_to_flush_to_db?
|
||||
redis.hkeys(COUNTER_REDIS_HASH).each do |key|
|
||||
|
||||
val = LUA_HGET_DEL.eval(
|
||||
redis,
|
||||
[COUNTER_REDIS_HASH, key]
|
||||
).to_i
|
||||
|
||||
# unlikely (protected by mutex), but protect just in case
|
||||
# could be a race condition in test
|
||||
if val > 0
|
||||
klass_name, db, date, local_key = key.split(",", 4)
|
||||
date = Date.strptime(date, "%Y%m%d")
|
||||
klass = Module.const_get(klass_name)
|
||||
|
||||
RailsMultisite::ConnectionManagement.with_connection(db) do
|
||||
klass.write_cache!(local_key, val, date)
|
||||
end
|
||||
end
|
||||
end
|
||||
end
|
||||
end
|
||||
end
|
||||
|
||||
def self.clear_flush_to_db_lock!
|
||||
Discourse.redis.without_namespace.del(DB_COOLDOWN_KEY)
|
||||
end
|
||||
|
||||
def self.flush_to_db_lock_ttl
|
||||
Discourse.redis.without_namespace.ttl(DB_COOLDOWN_KEY)
|
||||
end
|
||||
|
||||
def self.allowed_to_flush_to_db?
|
||||
Discourse.redis.without_namespace.set(DB_COOLDOWN_KEY, "1", ex: DB_FLUSH_COOLDOWN_SECONDS, nx: true)
|
||||
end
|
||||
|
||||
def self.queue(key, klass)
|
||||
QUEUE.push([key, klass, RailsMultisite::ConnectionManagement.current_db, Time.now.utc])
|
||||
end
|
||||
|
||||
def self.clear_queue!
|
||||
QUEUE.clear
|
||||
redis = Discourse.redis.without_namespace
|
||||
redis.del(COUNTER_REDIS_HASH)
|
||||
end
|
||||
|
||||
class_methods do
|
||||
def perform_increment!(key)
|
||||
CachedCounting.ensure_thread!
|
||||
CachedCounting.queue(key, self)
|
||||
end
|
||||
|
||||
def write_cache!(key, count, date)
|
||||
raise NotImplementedError
|
||||
end
|
||||
|
||||
end
|
||||
end
|
||||
|
|
|
@ -3,9 +3,6 @@
|
|||
class WebCrawlerRequest < ActiveRecord::Base
|
||||
include CachedCounting
|
||||
|
||||
# auto flush if older than this
|
||||
self.autoflush_seconds = 1.hour
|
||||
|
||||
cattr_accessor :max_record_age, :max_records_per_day
|
||||
|
||||
# only keep the top records based on request count
|
||||
|
@ -14,67 +11,28 @@ class WebCrawlerRequest < ActiveRecord::Base
|
|||
# delete records older than this
|
||||
self.max_record_age = 30.days
|
||||
|
||||
def self.increment!(user_agent, opts = nil)
|
||||
ua_list_key = user_agent_list_key
|
||||
Discourse.redis.sadd(ua_list_key, user_agent)
|
||||
Discourse.redis.expire(ua_list_key, 259200) # 3.days
|
||||
|
||||
perform_increment!(redis_key(user_agent), opts)
|
||||
def self.increment!(user_agent)
|
||||
perform_increment!(user_agent)
|
||||
end
|
||||
|
||||
def self.write_cache!(date = nil)
|
||||
if date.nil?
|
||||
write_cache!(Time.now.utc)
|
||||
write_cache!(Time.now.utc.yesterday)
|
||||
return
|
||||
end
|
||||
|
||||
self.last_flush = Time.now.utc
|
||||
|
||||
date = date.to_date
|
||||
ua_list_key = user_agent_list_key(date)
|
||||
|
||||
while user_agent = Discourse.redis.spop(ua_list_key)
|
||||
val = get_and_reset(redis_key(user_agent, date))
|
||||
|
||||
next if val == 0
|
||||
|
||||
self.where(id: req_id(date, user_agent)).update_all(["count = count + ?", val])
|
||||
end
|
||||
rescue Redis::CommandError => e
|
||||
raise unless e.message =~ /READONLY/
|
||||
nil
|
||||
end
|
||||
|
||||
def self.clear_cache!(date = nil)
|
||||
if date.nil?
|
||||
clear_cache!(Time.now.utc)
|
||||
clear_cache!(Time.now.utc.yesterday)
|
||||
return
|
||||
end
|
||||
|
||||
ua_list_key = user_agent_list_key(date)
|
||||
|
||||
while user_agent = Discourse.redis.spop(ua_list_key)
|
||||
Discourse.redis.del redis_key(user_agent, date)
|
||||
end
|
||||
|
||||
Discourse.redis.del(ua_list_key)
|
||||
def self.write_cache!(user_agent, count, date)
|
||||
where(id: request_id(date: date, user_agent: user_agent))
|
||||
.update_all(["count = count + ?", count])
|
||||
end
|
||||
|
||||
protected
|
||||
|
||||
def self.user_agent_list_key(time = Time.now.utc)
|
||||
"crawl_ua_list:#{time.strftime('%Y%m%d')}"
|
||||
def self.request_id(date:, user_agent:, retries: 0)
|
||||
id = where(date: date, user_agent: user_agent).pluck_first(:id)
|
||||
id ||= create!({ date: date, user_agent: user_agent }.merge(count: 0)).id
|
||||
rescue # primary key violation
|
||||
if retries == 0
|
||||
request_id(date: date, user_agent: user_agent, retries: 1)
|
||||
else
|
||||
raise
|
||||
end
|
||||
end
|
||||
|
||||
def self.redis_key(user_agent, time = Time.now.utc)
|
||||
"crawl_req:#{time.strftime('%Y%m%d')}:#{user_agent}"
|
||||
end
|
||||
|
||||
def self.req_id(date, user_agent)
|
||||
request_id(date: date, user_agent: user_agent)
|
||||
end
|
||||
end
|
||||
|
||||
# == Schema Information
|
||||
|
|
|
@ -0,0 +1,116 @@
|
|||
# frozen_string_literal: true
|
||||
|
||||
require 'rails_helper'
|
||||
|
||||
class TestCachedCounting
|
||||
def self.clear!
|
||||
@data = nil
|
||||
end
|
||||
|
||||
def self.data
|
||||
@data ||= {}
|
||||
end
|
||||
|
||||
def self.write_cache!(key, count, date)
|
||||
data[key] = count
|
||||
end
|
||||
end
|
||||
|
||||
describe CachedCounting do
|
||||
|
||||
it "should be default disabled in test" do
|
||||
expect(CachedCounting.enabled?).to eq(false)
|
||||
end
|
||||
|
||||
context "backing implementation" do
|
||||
|
||||
it "can correctly check for flush to db lock" do
|
||||
CachedCounting.clear_flush_to_db_lock!
|
||||
|
||||
expect(CachedCounting.allowed_to_flush_to_db?).to eq(true)
|
||||
expect(CachedCounting.allowed_to_flush_to_db?).to eq(false)
|
||||
t = CachedCounting::DB_FLUSH_COOLDOWN_SECONDS
|
||||
# let expiry be between 2 seconds to allow for slow calls and so on
|
||||
expect(CachedCounting.flush_to_db_lock_ttl).to be_between(t - 2, t)
|
||||
|
||||
CachedCounting.clear_flush_to_db_lock!
|
||||
end
|
||||
|
||||
context "with a test counting class" do
|
||||
before do
|
||||
CachedCounting.reset
|
||||
TestCachedCounting.clear!
|
||||
end
|
||||
|
||||
it "can dispatch counts to backing class" do
|
||||
|
||||
CachedCounting.queue("a,a", TestCachedCounting)
|
||||
CachedCounting.queue("a,a", TestCachedCounting)
|
||||
CachedCounting.queue("b", TestCachedCounting)
|
||||
|
||||
CachedCounting.flush_in_memory
|
||||
CachedCounting.flush_to_db
|
||||
|
||||
expect(TestCachedCounting.data).to eq({ "a,a" => 2, "b" => 1 })
|
||||
|
||||
end
|
||||
end
|
||||
end
|
||||
|
||||
context "active record" do
|
||||
class RailsCacheCounter < ActiveRecord::Base
|
||||
include CachedCounting
|
||||
self.table_name = "posts"
|
||||
|
||||
def self.cache_data
|
||||
@cache_data ||= {}
|
||||
end
|
||||
|
||||
def self.clear_cache_data
|
||||
@cache_data = nil
|
||||
end
|
||||
|
||||
def self.write_cache!(key, val, date)
|
||||
cache_data[[key, date]] = val
|
||||
end
|
||||
end
|
||||
|
||||
before do
|
||||
CachedCounting.reset
|
||||
CachedCounting.enable
|
||||
end
|
||||
|
||||
after do
|
||||
CachedCounting.disable
|
||||
end
|
||||
|
||||
it "can dispatch data via background thread" do
|
||||
|
||||
freeze_time
|
||||
d1 = Time.now.utc.to_date
|
||||
|
||||
RailsCacheCounter.perform_increment!("a,a")
|
||||
RailsCacheCounter.perform_increment!("b")
|
||||
20.times do
|
||||
RailsCacheCounter.perform_increment!("a,a")
|
||||
end
|
||||
|
||||
freeze_time 2.days.from_now
|
||||
d2 = Time.now.utc.to_date
|
||||
|
||||
RailsCacheCounter.perform_increment!("a,a")
|
||||
RailsCacheCounter.perform_increment!("d")
|
||||
|
||||
CachedCounting.flush
|
||||
|
||||
expected = {
|
||||
["a,a", d1] => 21,
|
||||
["b", d1] => 1,
|
||||
["a,a", d2] => 1,
|
||||
["d", d2] => 1,
|
||||
}
|
||||
|
||||
expect(RailsCacheCounter.cache_data).to eq(expected)
|
||||
end
|
||||
end
|
||||
end
|
|
@ -15,23 +15,17 @@ describe Middleware::RequestTracker do
|
|||
end
|
||||
|
||||
before do
|
||||
ApplicationRequest.clear_cache!
|
||||
ApplicationRequest.enable
|
||||
CachedCounting.reset
|
||||
CachedCounting.enable
|
||||
end
|
||||
|
||||
after do
|
||||
ApplicationRequest.disable
|
||||
ApplicationRequest.clear_cache!
|
||||
CachedCounting.disable
|
||||
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")
|
||||
|
@ -39,6 +33,8 @@ describe Middleware::RequestTracker do
|
|||
middleware = Middleware::RequestTracker.new(->(env) { ["200", { "Content-Type" => "text/html" }, [""]] })
|
||||
middleware.call(env("HTTP_USER_AGENT" => agent))
|
||||
|
||||
CachedCounting.flush
|
||||
|
||||
expect(WebCrawlerRequest.where(user_agent: agent.encode('utf-8')).count).to eq(1)
|
||||
end
|
||||
|
||||
|
@ -63,7 +59,8 @@ describe Middleware::RequestTracker do
|
|||
log_tracked_view("1")
|
||||
log_tracked_view("false")
|
||||
log_tracked_view("0")
|
||||
ApplicationRequest.write_cache!
|
||||
|
||||
CachedCounting.flush
|
||||
|
||||
expect(ApplicationRequest.page_view_anon.first.count).to eq(2)
|
||||
end
|
||||
|
@ -95,7 +92,7 @@ describe Middleware::RequestTracker do
|
|||
|
||||
Middleware::RequestTracker.log_request(data)
|
||||
|
||||
ApplicationRequest.write_cache!
|
||||
CachedCounting.flush
|
||||
|
||||
expect(ApplicationRequest.http_total.first.count).to eq(4)
|
||||
expect(ApplicationRequest.http_2xx.first.count).to eq(4)
|
||||
|
@ -114,7 +111,10 @@ describe Middleware::RequestTracker do
|
|||
), ["200", { "Content-Type" => 'text/html' }], 0.1)
|
||||
|
||||
Middleware::RequestTracker.log_request(data)
|
||||
ApplicationRequest.write_cache!
|
||||
|
||||
CachedCounting.flush
|
||||
CachedCounting.reset
|
||||
|
||||
expect(ApplicationRequest.page_view_crawler.first.count).to eq(1)
|
||||
|
||||
# ...but count our mobile app user agents as regular visits
|
||||
|
@ -123,7 +123,8 @@ describe Middleware::RequestTracker do
|
|||
), ["200", { "Content-Type" => 'text/html' }], 0.1)
|
||||
|
||||
Middleware::RequestTracker.log_request(data)
|
||||
ApplicationRequest.write_cache!
|
||||
|
||||
CachedCounting.flush
|
||||
|
||||
expect(ApplicationRequest.page_view_crawler.first.count).to eq(1)
|
||||
expect(ApplicationRequest.page_view_anon.first.count).to eq(1)
|
||||
|
@ -157,7 +158,7 @@ describe Middleware::RequestTracker do
|
|||
Middleware::RequestTracker.log_request(anon_data)
|
||||
Middleware::RequestTracker.log_request(logged_in_data)
|
||||
|
||||
ApplicationRequest.write_cache!
|
||||
CachedCounting.flush
|
||||
|
||||
expect(ApplicationRequest.http_total.first.count).to eq(2)
|
||||
expect(ApplicationRequest.http_2xx.first.count).to eq(2)
|
||||
|
@ -172,7 +173,7 @@ describe Middleware::RequestTracker do
|
|||
Middleware::RequestTracker.log_request(anon_data)
|
||||
Middleware::RequestTracker.log_request(logged_in_data)
|
||||
|
||||
ApplicationRequest.write_cache!
|
||||
CachedCounting.flush
|
||||
|
||||
expect(ApplicationRequest.http_total.first.count).to eq(2)
|
||||
expect(ApplicationRequest.http_2xx.first.count).to eq(2)
|
||||
|
|
|
@ -5,114 +5,43 @@ require 'rails_helper'
|
|||
describe ApplicationRequest do
|
||||
before do
|
||||
ApplicationRequest.enable
|
||||
ApplicationRequest.last_flush = Time.now.utc
|
||||
CachedCounting.reset
|
||||
CachedCounting.enable
|
||||
end
|
||||
|
||||
after do
|
||||
ApplicationRequest.disable
|
||||
ApplicationRequest.clear_cache!
|
||||
CachedCounting.disable
|
||||
end
|
||||
|
||||
def inc(key, opts = nil)
|
||||
ApplicationRequest.increment!(key, opts)
|
||||
def inc(key)
|
||||
ApplicationRequest.increment!(key)
|
||||
end
|
||||
|
||||
def disable_date_flush!
|
||||
freeze_time(Time.now)
|
||||
ApplicationRequest.last_flush = Time.now.utc
|
||||
end
|
||||
it "can log app requests" do
|
||||
freeze_time
|
||||
d1 = Time.now.utc.to_date
|
||||
|
||||
context "readonly test" do
|
||||
it 'works even if redis is in readonly' do
|
||||
disable_date_flush!
|
||||
|
||||
inc(:http_total)
|
||||
inc(:http_total)
|
||||
|
||||
Discourse.redis.without_namespace.stubs(:eval).raises(Redis::CommandError.new("READONLY"))
|
||||
Discourse.redis.without_namespace.stubs(:evalsha).raises(Redis::CommandError.new("READONLY"))
|
||||
Discourse.redis.without_namespace.stubs(:set).raises(Redis::CommandError.new("READONLY"))
|
||||
|
||||
# flush will be deferred no error raised
|
||||
inc(:http_total, autoflush: 3)
|
||||
ApplicationRequest.write_cache!
|
||||
|
||||
Discourse.redis.without_namespace.unstub(:eval)
|
||||
Discourse.redis.without_namespace.unstub(:evalsha)
|
||||
Discourse.redis.without_namespace.unstub(:set)
|
||||
|
||||
inc(:http_total, autoflush: 3)
|
||||
expect(ApplicationRequest.http_total.first.count).to eq(3)
|
||||
4.times do
|
||||
inc("http_2xx")
|
||||
end
|
||||
end
|
||||
|
||||
it 'logs nothing for an unflushed increment' do
|
||||
ApplicationRequest.increment!(:page_view_anon)
|
||||
expect(ApplicationRequest.count).to eq(0)
|
||||
end
|
||||
inc("http_background")
|
||||
|
||||
it 'can automatically flush' do
|
||||
disable_date_flush!
|
||||
freeze_time 1.day.from_now
|
||||
d2 = Time.now.utc.to_date
|
||||
|
||||
inc(:http_total)
|
||||
inc(:http_total)
|
||||
inc(:http_total, autoflush: 3)
|
||||
inc("page_view_crawler")
|
||||
inc("http_2xx")
|
||||
|
||||
expect(ApplicationRequest.http_total.first.count).to eq(3)
|
||||
CachedCounting.flush
|
||||
|
||||
inc(:http_total)
|
||||
inc(:http_total)
|
||||
inc(:http_total, autoflush: 3)
|
||||
expect(ApplicationRequest.find_by(date: d1, req_type: "http_2xx").count).to eq(4)
|
||||
expect(ApplicationRequest.find_by(date: d1, req_type: "http_background").count).to eq(1)
|
||||
|
||||
expect(ApplicationRequest.http_total.first.count).to eq(6)
|
||||
end
|
||||
|
||||
it 'can flush based on time' do
|
||||
t1 = Time.now.utc.at_midnight
|
||||
freeze_time(t1)
|
||||
ApplicationRequest.write_cache!
|
||||
inc(:http_total)
|
||||
expect(ApplicationRequest.count).to eq(0)
|
||||
|
||||
freeze_time(t1 + ApplicationRequest.autoflush_seconds + 1)
|
||||
inc(:http_total)
|
||||
|
||||
expect(ApplicationRequest.count).to eq(1)
|
||||
end
|
||||
|
||||
it 'flushes yesterdays results' do
|
||||
t1 = Time.now.utc.at_midnight
|
||||
freeze_time(t1)
|
||||
inc(:http_total)
|
||||
freeze_time(t1.tomorrow)
|
||||
inc(:http_total)
|
||||
|
||||
ApplicationRequest.write_cache!
|
||||
expect(ApplicationRequest.count).to eq(2)
|
||||
end
|
||||
|
||||
it 'clears cache correctly' do
|
||||
# otherwise we have test pollution
|
||||
inc(:page_view_anon)
|
||||
ApplicationRequest.clear_cache!
|
||||
ApplicationRequest.write_cache!
|
||||
|
||||
expect(ApplicationRequest.count).to eq(0)
|
||||
end
|
||||
|
||||
it 'logs a few counts once flushed' do
|
||||
time = Time.now.at_midnight
|
||||
freeze_time(time)
|
||||
|
||||
3.times { inc(:http_total) }
|
||||
2.times { inc(:http_2xx) }
|
||||
4.times { inc(:http_3xx) }
|
||||
|
||||
ApplicationRequest.write_cache!
|
||||
|
||||
expect(ApplicationRequest.http_total.first.count).to eq(3)
|
||||
expect(ApplicationRequest.http_2xx.first.count).to eq(2)
|
||||
expect(ApplicationRequest.http_3xx.first.count).to eq(4)
|
||||
expect(ApplicationRequest.find_by(date: d2, req_type: "page_view_crawler").count).to eq(1)
|
||||
expect(ApplicationRequest.find_by(date: d2, req_type: "http_2xx").count).to eq(1)
|
||||
|
||||
end
|
||||
|
||||
end
|
||||
|
|
|
@ -1187,11 +1187,6 @@ describe Report do
|
|||
before do
|
||||
freeze_time(Time.now.at_midnight)
|
||||
Theme.clear_default!
|
||||
ApplicationRequest.clear_cache!
|
||||
end
|
||||
|
||||
after do
|
||||
ApplicationRequest.clear_cache!
|
||||
end
|
||||
|
||||
let(:reports) { Report.find('consolidated_page_views') }
|
||||
|
@ -1205,12 +1200,22 @@ describe Report do
|
|||
end
|
||||
|
||||
context "with data" do
|
||||
it "works" do
|
||||
before do
|
||||
CachedCounting.reset
|
||||
CachedCounting.enable
|
||||
ApplicationRequest.enable
|
||||
end
|
||||
|
||||
after do
|
||||
ApplicationRequest.disable
|
||||
CachedCounting.disable
|
||||
end
|
||||
it "works" do
|
||||
3.times { ApplicationRequest.increment!(:page_view_crawler) }
|
||||
2.times { ApplicationRequest.increment!(:page_view_logged_in) }
|
||||
ApplicationRequest.increment!(:page_view_anon)
|
||||
ApplicationRequest.write_cache!
|
||||
|
||||
CachedCounting.flush
|
||||
|
||||
page_view_crawler_report = reports.data.find { |r| r[:req] == "page_view_crawler" }
|
||||
page_view_logged_in_report = reports.data.find { |r| r[:req] == "page_view_logged_in" }
|
||||
|
@ -1225,8 +1230,6 @@ describe Report do
|
|||
expect(page_view_anon_report[:color]).to eql("#40c8ff")
|
||||
expect(page_view_anon_report[:data][0][:y]).to eql(1)
|
||||
ensure
|
||||
ApplicationRequest.disable
|
||||
ApplicationRequest.clear_cache!
|
||||
end
|
||||
end
|
||||
end
|
||||
|
|
|
@ -4,115 +4,37 @@ require 'rails_helper'
|
|||
|
||||
describe WebCrawlerRequest do
|
||||
before do
|
||||
WebCrawlerRequest.last_flush = Time.now.utc
|
||||
WebCrawlerRequest.clear_cache!
|
||||
CachedCounting.reset
|
||||
CachedCounting.enable
|
||||
end
|
||||
|
||||
after do
|
||||
WebCrawlerRequest.clear_cache!
|
||||
CachedCounting.disable
|
||||
end
|
||||
|
||||
def inc(user_agent, opts = nil)
|
||||
WebCrawlerRequest.increment!(user_agent, opts)
|
||||
it "can log crawler requests" do
|
||||
freeze_time
|
||||
d1 = Time.now.utc.to_date
|
||||
|
||||
4.times do
|
||||
WebCrawlerRequest.increment!("Googlebot")
|
||||
end
|
||||
|
||||
WebCrawlerRequest.increment!("Bingbot")
|
||||
|
||||
freeze_time 1.day.from_now
|
||||
d2 = Time.now.utc.to_date
|
||||
|
||||
WebCrawlerRequest.increment!("Googlebot")
|
||||
WebCrawlerRequest.increment!("Superbot")
|
||||
|
||||
CachedCounting.flush
|
||||
|
||||
expect(WebCrawlerRequest.find_by(date: d2, user_agent: "Googlebot").count).to eq(1)
|
||||
expect(WebCrawlerRequest.find_by(date: d2, user_agent: "Superbot").count).to eq(1)
|
||||
|
||||
expect(WebCrawlerRequest.find_by(date: d1, user_agent: "Googlebot").count).to eq(4)
|
||||
expect(WebCrawlerRequest.find_by(date: d1, user_agent: "Bingbot").count).to eq(1)
|
||||
end
|
||||
|
||||
def disable_date_flush!
|
||||
freeze_time(Time.now)
|
||||
WebCrawlerRequest.last_flush = Time.now.utc
|
||||
end
|
||||
|
||||
def web_crawler_request(user_agent)
|
||||
WebCrawlerRequest.where(user_agent: user_agent).first
|
||||
end
|
||||
|
||||
it 'works even if redis is in readonly' do
|
||||
disable_date_flush!
|
||||
|
||||
inc('Googlebot')
|
||||
inc('Googlebot')
|
||||
|
||||
Discourse.redis.without_namespace.stubs(:eval).raises(Redis::CommandError.new("READONLY"))
|
||||
Discourse.redis.without_namespace.stubs(:evalsha).raises(Redis::CommandError.new("READONLY"))
|
||||
Discourse.redis.without_namespace.stubs(:set).raises(Redis::CommandError.new("READONLY"))
|
||||
|
||||
inc('Googlebot', autoflush: 3)
|
||||
WebCrawlerRequest.write_cache!
|
||||
|
||||
Discourse.redis.without_namespace.unstub(:eval)
|
||||
Discourse.redis.without_namespace.unstub(:evalsha)
|
||||
Discourse.redis.without_namespace.unstub(:set)
|
||||
|
||||
inc('Googlebot', autoflush: 3)
|
||||
expect(web_crawler_request('Googlebot').count).to eq(3)
|
||||
end
|
||||
|
||||
it 'logs nothing for an unflushed increment' do
|
||||
WebCrawlerRequest.increment!('Googlebot')
|
||||
expect(WebCrawlerRequest.count).to eq(0)
|
||||
end
|
||||
|
||||
it 'can automatically flush' do
|
||||
disable_date_flush!
|
||||
|
||||
inc('Googlebot', autoflush: 3)
|
||||
expect(web_crawler_request('Googlebot')).to_not be_present
|
||||
expect(WebCrawlerRequest.count).to eq(0)
|
||||
inc('Googlebot', autoflush: 3)
|
||||
expect(web_crawler_request('Googlebot')).to_not be_present
|
||||
inc('Googlebot', autoflush: 3)
|
||||
expect(web_crawler_request('Googlebot').count).to eq(3)
|
||||
expect(WebCrawlerRequest.count).to eq(1)
|
||||
|
||||
3.times { inc('Googlebot', autoflush: 3) }
|
||||
expect(web_crawler_request('Googlebot').count).to eq(6)
|
||||
expect(WebCrawlerRequest.count).to eq(1)
|
||||
end
|
||||
|
||||
it 'can flush based on time' do
|
||||
t1 = Time.now.utc.at_midnight
|
||||
freeze_time(t1)
|
||||
WebCrawlerRequest.write_cache!
|
||||
inc('Googlebot')
|
||||
expect(WebCrawlerRequest.count).to eq(0)
|
||||
|
||||
freeze_time(t1 + WebCrawlerRequest.autoflush_seconds + 1)
|
||||
inc('Googlebot')
|
||||
|
||||
expect(WebCrawlerRequest.count).to eq(1)
|
||||
end
|
||||
|
||||
it 'flushes yesterdays results' do
|
||||
t1 = Time.now.utc.at_midnight
|
||||
freeze_time(t1)
|
||||
inc('Googlebot')
|
||||
freeze_time(t1.tomorrow)
|
||||
inc('Googlebot')
|
||||
|
||||
WebCrawlerRequest.write_cache!
|
||||
expect(WebCrawlerRequest.count).to eq(2)
|
||||
end
|
||||
|
||||
it 'clears cache correctly' do
|
||||
inc('Googlebot')
|
||||
inc('Twitterbot')
|
||||
WebCrawlerRequest.clear_cache!
|
||||
WebCrawlerRequest.write_cache!
|
||||
|
||||
expect(WebCrawlerRequest.count).to eq(0)
|
||||
end
|
||||
|
||||
it 'logs a few counts once flushed' do
|
||||
time = Time.now.at_midnight
|
||||
freeze_time(time)
|
||||
|
||||
3.times { inc('Googlebot') }
|
||||
2.times { inc('Twitterbot') }
|
||||
4.times { inc('Bingbot') }
|
||||
|
||||
WebCrawlerRequest.write_cache!
|
||||
|
||||
expect(web_crawler_request('Googlebot').count).to eq(3)
|
||||
expect(web_crawler_request('Twitterbot').count).to eq(2)
|
||||
expect(web_crawler_request('Bingbot').count).to eq(4)
|
||||
end
|
||||
end
|
||||
|
|
|
@ -194,6 +194,8 @@ RSpec.configure do |config|
|
|||
config.infer_base_class_for_anonymous_controllers = true
|
||||
|
||||
config.before(:suite) do
|
||||
CachedCounting.disable
|
||||
|
||||
begin
|
||||
ActiveRecord::Migration.check_pending!
|
||||
rescue ActiveRecord::PendingMigrationError
|
||||
|
|
Loading…
Reference in New Issue