Jbuilder Rails caching is slower

Question

I've tried to use caching with collections (with multiple solutions) the problem is that when ever I try caching the response become slower consider the following example of a collection that renders 2 partials for every item in it (around 25 item)

json.data do
  json.array! @organizations do |organization|
    json.partial! 'api/v1/organizations/organization', organization: organization
    json.partial! 'api/v1/organizations/links', organization: organization
  end
end

without caching the average response time is around ~38ms (on average)

now with caching

json.data do
  json.array! @organizations do |organization|
    json.cache! organization do
      json.partial! 'api/v1/organizations/organization', organization: organization
      json.partial! 'api/v1/organizations/links', organization: organization
    end
  end
end

with the jbuilder default caching and dalli store is properly installed and configured (I could verify that there was no cache miss)

the average response is around ~59ms (on average)

using the syntax found on Cache Digest

json.data do
  json.cache! @organizations do
    json.partial! 'api/v1/organizations/organization', collection: @organizations, as: :organization
    json.partial! 'api/v1/organizations/links', collection: @organizations, as: :organization
  end
end

the average response time is ~41ms (on average), and the response is different than the other responses

# Instead of getting
[{ data:{}, links:{} }, {{ data:{}, links:{} }]
# I get
[{ data:{}, data:{}, links:{}, links:{} }]

but the cache digest of the file is a very big string that will easily exceed the unix max file name length. this is the filename for example.

Cache write: jbuilder/organizations/5509f9284162643526000000-20150322012449497000000/organizations/5509e5924162643056020000-20150320223230684000000/organizations/550b54d8416264add2040000-20150321004501311000000/organizations/550e35704162640a98030000-20150322032224768000000/organizations/550e357b4162640a98050000-20150322032235260000000/organizations/550e35834162640a98080000-20150322032243162000000/organizations/550e35894162640a980a0000-20150322032249767000000/organizations/550e35904162640a980c0000-20150322032256464000000/organizations/550e35944162640a980e0000-20150322032300519000000/organizations/550e35984162640a98100000-20150322032304428000000/organizations/550e359c4162640a98120000-20150322032308542000000/organizations/550e35a04162640a98140000-20150322032312514000000/organizations/550e35a54162640a98160000-20150322032317066000000/organizations/550e35a84162640a98180000-20150322032320850000000/organizations/550e35ac4162640a981a0000-20150322032324716000000/organizations/550e35b04162640a981c0000-20150322032328643000000/organizations/550e35b54162640a981e0000-20150322032333651000000/organizations/550e35ba4162640a98200000-20150322032338114000000/organizations/550e35bd4162640a98220000-20150322032341889000000/organizations/550e35c14162640a98240000-20150322032345602000000/organizations/550e35c54162640a98260000-20150322032349739000000/3fcda1f9c320ab4284da56b4b2337cf5`

I've also tired Jbuilder Cache Multi

json.data do
  json.cache_collection! @organizations do |organization|
    json.partial! 'api/v1/organizations/organization', organization: organization
    json.partial! 'api/v1/organizations/links', organization: organization
  end
end

and the response was around ~57ms (on average)

plus with both jbuilder cache and multi I'm getting a lot of these in the logs

  Cache digest for app/views/api/v1/organizations/index.json.jbuilder: 3a51096b9c8da6a2cdb5b5a33ee58ea4
  Cache digest for app/views/api/v1/organizations/_organization.json.jbuilder: 4a1f1d49c90fdd867d88701f8a3fd6e1
  Cache digest for app/views/api/v1/organizations/_links.json.jbuilder: f2a881e125f95421d566edd571fdec73
  Cache digest for app/views/api/v1/organizations/index.json.jbuilder: 3a51096b9c8da6a2cdb5b5a33ee58ea4
  Cache digest for app/views/api/v1/organizations/_organization.json.jbuilder: 4a1f1d49c90fdd867d88701f8a3fd6e1
  Cache digest for app/views/api/v1/organizations/_links.json.jbuilder: f2a881e125f95421d566edd571fdec73
  Cache digest for app/views/api/v1/organizations/index.json.jbuilder: 3a51096b9c8da6a2cdb5b5a33ee58ea4
  Cache digest for app/views/api/v1/organizations/_organization.json.jbuilder: 4a1f1d49c90fdd867d88701f8a3fd6e1

so is it something wrong with my implementation or machine or local environment ? Rails 4.2.0, and Jbuilder 2.2.11

I also posted this issue to jbuilder #259

Answer 1

To elaborate on my quote, as of right now (v2.2.12 of JBuilder), caching partials in JBuilder is only really worth it if one or both of the following are true:

• You can skip AR queries (or computation) that are on average more expensive than accessing cache

  Going to cache is usually a network call in the usual Rails stack, and while a DB query can be expensive, the cost of going over the network to get a serialized ActiveSupport blob, and then deserializing into a hash in Ruby is expensive and has to be done inside the Ruby VM. This is not good for performance.

• The size of the JSON blob produced is small

  As a corollary, if you have a small query, but produce a lot of JSON, you will quickly hit degraded performance as the blob is deserialized from an ActiveSupport blob, and then again on the way out to raw JSON. Remember, the cache does not store raw JSON, but a serialized intermediary format. This means, for every additional byte of JSON stored in the cache, you're going to have about 4 more bytes over the wire (from the serialized AS representation) and probably spend just as long deserializing as it would have taken to just compute the partial anyhow.

If you have an endpoint that produces a giant JSON blob, my recommendation is to just manually conditionally render the blob in the controller and cache it as a raw string in Rails.cache. The cost of recomputing all of your JSON now and then is probably less than going through JBuilder's cache machinery on every call.

Answer 2

As the time of this answer... this is how jbuilder works... and as I could quote from the github issue

@vincentwoo

The issue is that jbuilder caching is fairly naive - it basically dumps a serialized version of a giant activerecord blob into the cache store, then pulls it out, deserializes it, and then EVENTUALLY serializes THAT to JSON.

In the future, jbuilder will hopefully act directly on strings, but until then, I think jbuilder caching is best not used russian-doll style.

and @rwz (one of the collaborators)

Currently caching provides benefits only when it allows to skip some of AR queries or you're using really computionally heavy view helpers.

When you already have the records fetched and only perform basic extractions, caching only slows things down.