Low perfomance of local_cache's read_entry and write_entry

[hoangtuyb96]

Steps to reproduce

Here's script to reproduce the low performance.
https://gist.github.com/hoangtuyb96/5e9a16969ccac2e416a88e0c17cc8e5d

Procedure:

• Save it ( i.e as cache.rb )
• Change the database's information
• Run it
  • To benchmark in specific rails version: run cache.rb path_of_cache specific_rails_version

Related PR in rails 6.1.0:

• Return a copy of the cache entry when local_cache exists: #36656
• Duplicate the cached value before writing it in the local cache #37587

Expected behavior

The performance in rails 6.0.x and 6.1.0 should be equal.

Actual behavior

When i ran above script, i got this result.

In rails 6.0.x

== Benchmarking read_entry code and write_entry code in rails 6.0.4
Warming up --------------------------------------
fetch in rails 6.0.4    12.563k i/100ms
write in rails 6.0.4     8.000  i/100ms
Calculating -------------------------------------
fetch in rails 6.0.4    123.118k (± 4.6%) i/s -    615.587k in   5.011083s
write in rails 6.0.4     84.463  (± 3.6%) i/s -    424.000  in   5.028694s

In rails 6.1.0

== Benchmarking read_entry code and write_entry code in rails 6.1.0
Warming up --------------------------------------
fetch in rails 6.1.0    33.000  i/100ms
write in rails 6.1.0     4.000  i/100ms
Calculating -------------------------------------
fetch in rails 6.1.0    322.163  (± 8.1%) i/s -      1.617k in   5.057517s
write in rails 6.1.0     43.771  (± 9.1%) i/s -    220.000  in   5.086859s

I saw a serious speed degradation.

System configuration

Ruby version: 2.7.2

Rails version: 6.0.x and 6.1.0

[casperisfine]

Ok, so, the regression seem quite bad indeed, however I think there a few things that need to be stated:

LocalCache was very fast on 6.0, because it was pretty much just a hash lookup, however it was bugged, #36656 and #37587 slowed it down, but it also made it correct. These bugs were really nasty.

Here's the timings I get:

fetch in rails 6.0.4    116.119k (± 2.6%) i/s -    587.850k in   5.065835s
write in rails 6.0.4    103.298  (± 2.9%) i/s -    520.000  in   5.037961s

fetch in rails 6.1.0     74.855  (± 4.0%) i/s -    378.000  in   5.056337s
write in rails 6.1.0     54.131  (±11.1%) i/s -    265.000  in   5.011408s

fetch in rails 7.0.0  239.083  (± 6.7%) i/s -      1.196k in   5.032613s
write in rails 7.0.0   71.585  (± 2.8%) i/s -    360.000  in   5.031570s

So 7.0 is over 3 times faster on read, but still almost 500x slower than 6.0.0. So maybe it's worth backporting the performance patch, but I'm starting to wonder if local cache is really worth it in general.

[casperisfine]

Another thing, for both fixes, the perf overhead is of similar nature. We call dup_value!, which pretty much is Marshal.load(Marshal.dump(value)). So the larger the value the larger the degradation.

So your benchmark shows a 322x slower result, if we reduce the hash to contain 10 AR models rather than 1k, it's down to 22x slower. A good part of that might be wether you go over the 1k payload size, at which point GZIP compression kicks in, and is way slower.

This isn't to minimize the impact but I think it's important to say it.

Now to answer my own rhetorical question:

I'm starting to wonder if local cache is really worth it in general.

The actual cache adapter (FileStore in the benchmark) has to serialize / deserialize the record regardless. Local cache used to be WAY faster on hit because it would save that deserialization. But I don't think we can reasonably go back to that.

However we can in theory avoid any extra serialization/deserialization by using the same entry object than the real cache store. That's kind of what I was going toward with #42014, and we can probably improve that a bit more.

So at best the local cache usefulness would be limited to save the network roundtrip (if you use redis / memcached).

[hoangtuyb96]

Thank you for advising me.

So at best the local cache usefulness would be limited to save the network roundtrip (if you use redis / memcached).

So instead of using local cache, should i use redis / memcached?

But when i saw mem_cache_store's code, i realized Strategy::LocalCache is prepended. That means that even using memcached, the speed is still significantly slower.
https://github.com/rails/rails/blob/main/activesupport/lib/active_support/cache/mem_cache_store.rb#L47

What I'm most interested in here is reading speed from localcache. So, even using redis I'm not sure if it's faster or equal to using localcache.

[casperisfine]

So instead of using local cache, should i use redis / memcached?

It's not one or the other, when you read a key, it first look into the local cache, and if it's not there it fallback to whatever cache backend you use.

So assuming we do backport the perf improvements to 6.1, the local cache will only save the network roundtrip (and internal Redis/memcached latency).

But when i saw mem_cache_store's code, i realized Strategy::LocalCache is prepended.

Yes, but you can still disable it by removing the local cache middleware:

    initializer :disable_local_cache do |app|
      app.config.middleware.delete Rails.cache.middleware
    end

[casperisfine]

At the very least we should remove LocalCache from the FileStore: #42626

Now we can try to backport some of the perf fixes, but it's tricky. We can't change the Entry internal state, otherwise it can break apps on upgrade, that's the whole reason behind #42025, allowing to evolve the serialization format, and be smarter with it.

For your specific case I'd recommend disabling local caching.

[hoangtuyb96]

I installed memcached and tried to use it. In the script below, i didn't create localcache before benchmarking.

Script 1: Using memcached with localstore in rails 6.0.4

# run: ruby memcached.rb 6.0.4
require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"
  gem "rails", ARGV[0] || "6.0.4"
  gem 'benchmark-ips'
  gem "mysql2"
  gem "pry"
  gem "dalli"
end

require "active_record"
require "logger"
require 'benchmark/ips'

# This connection will do for database-independent bug reports.
ActiveRecord::Base.establish_connection(adapter: "mysql2", database: 'test', host: 'localhost', user: 'root', password: '')
ActiveRecord::Base.logger = Logger.new(STDOUT)

ActiveRecord::Schema.define do
  create_table :users, force: true do |t|
    t.string :name
    t.integer :phone
  end
end

class ApplicationRecord < ActiveRecord::Base
  self.abstract_class = true
end

class User < ApplicationRecord
end

1_000.times { |i| User.create(name: "test #{i}") }

# Setup cache with FileStore
cache = ActiveSupport::Cache::MemCacheStore.new(['localhost:11211'])

# Setup localcache
ActiveSupport::Cache::Strategy::LocalCache::LocalCacheRegistry.set_cache_for(
  cache.middleware.local_cache_key,
  ActiveSupport::Cache::Strategy::LocalCache::LocalStore.new
)

h = {}
h = User.last(1000).each { |u| h[u.id] = u }

puts "== Benchmarking read_entry code and write_entry code in rails #{Rails.version}"

Benchmark.ips do |x|
  x.report("fetch in rails #{Rails.version}") {
    cache.fetch('key', compress: false) { h }
  }

  x.report("write in rails #{Rails.version}") {
    cache.write("key+#{Time.now}", h, compress: false) { h }
  }
end

Script 2: Using memcached without localstore in rails 6.1.3.2

# run: ruby memcached.rb 6.1.3.2
require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"
  gem "rails", ARGV[0] || "6.0.4"
  gem 'benchmark-ips'
  gem "mysql2"
  gem "pry"
  gem "dalli"
end

require "active_record"
require "logger"
require 'benchmark/ips'

# This connection will do for database-independent bug reports.
ActiveRecord::Base.establish_connection(adapter: "mysql2", database: 'test', host: 'localhost', user: 'root', password: '')
ActiveRecord::Base.logger = Logger.new(STDOUT)

ActiveRecord::Schema.define do
  create_table :users, force: true do |t|
    t.string :name
    t.integer :phone
  end
end

class ApplicationRecord < ActiveRecord::Base
  self.abstract_class = true
end

class User < ApplicationRecord
end

1_000.times { |i| User.create(name: "test #{i}") }

# Setup cache with FileStore
cache = ActiveSupport::Cache::MemCacheStore.new(['localhost:11211'])

h = {}
h = User.last(1000).each { |u| h[u.id] = u }

puts "== Benchmarking read_entry code and write_entry code in rails #{Rails.version}"

Benchmark.ips do |x|
  x.report("fetch in rails #{Rails.version}") {
    cache.fetch('key', compress: false) { h }
  }

  x.report("write in rails #{Rails.version}") {
    cache.write("key+#{Time.now}", h, compress: false) { h }
  }
end

And this is the output i got from 2 scripts.

Script 1

== Benchmarking read_entry code and write_entry code in rails 6.0.4
Warming up --------------------------------------
fetch in rails 6.0.4    19.335k i/100ms
write in rails 6.0.4     9.000  i/100ms
Calculating -------------------------------------
fetch in rails 6.0.4    189.666k (± 4.6%) i/s -    966.750k in   5.108241s
write in rails 6.0.4     91.790  (± 5.4%) i/s -    459.000  in   5.018058s

Script 2

== Benchmarking read_entry code and write_entry code in rails 6.1.3.2
Warming up --------------------------------------
fetch in rails 6.1.3.2
                        19.000  i/100ms
write in rails 6.1.3.2
                        12.000  i/100ms
Calculating -------------------------------------
fetch in rails 6.1.3.2
                        193.660  (± 7.7%) i/s -    969.000  in   5.032902s
write in rails 6.1.3.2
                        123.427  (± 4.1%) i/s -    624.000  in   5.063249s

Looking at the results, I don't think disabling localcache will improve speed. Is there any way you can keep the performance like in Rails 6?

[casperisfine]

In the script below

I don't understand the point of this benchmark. What I was pointing at is the usefulness of local cache with memcached. So what would need to be compared would be memcached with and without local cache on 6.1/7.0.

Is there any way you can keep the performance like in Rails 6?

No it's impossible, what's slow is the deep_dup, and it's required to prevent #36656.

[casperisfine]

Also I have to ask, why is local cache this important to you? Does your app actually fetch the same key multiple time during a request cycle? I'm really starting to doubt the usefulness of the local cache.

[hoangtuyb96]

I don't understand the point of this benchmark. What I was pointing at is the usefulness of local cache with memcached. So what would need to be compared would be memcached with and without local cache on 6.1/7.0.

No it's impossible, what's slow is the deep_dup, and it's required to prevent #36656.

Oh, i got it. Sorry for the inconvenience that I have caused you.

Does your app actually fetch the same key multiple time during a request cycle?

Yeah, that's right.
I have a huge data that is called many times during a request cycle. So, to improve speed of request i used localcache.

[casperisfine]

Oh, i got it. Sorry for the inconvenience that I have caused you.

No worries at all!

I have a huge data that is called many times during a request cycle.

Ah, I see. Yeah your use case is definitely the poster child for local cache :/.

As said previously I'm afraid we won't ever be able to restore the initial performance without restoring the potential for brittle bugs. So I'd suggest you just sidestep this issue by implementing your own request scoped cache for that specific usage.

[hoangtuyb96]

Let me try to implement your suggestion. Really appreciate your constant support. 👍

[casperisfine]

Forgot to mention, CurrentAttributes should make implementing such cache quite easy: https://api.rubyonrails.org/classes/ActiveSupport/CurrentAttributes.html