Caching is working but slower

[a14m]

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 StackOverflow

[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.

[rwz]

Well, @vincentwoo is right. 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.

[a14m]

Can anyone confirm that this behaviour also exist on RABL ?

[vincentwoo]

@artmees: I think that question is best asked to the RABL user group or github issues list.

@rwz: Any chance you could document the caching tradeoffs of jbuilder in the README? Have definitely seen this issue trip up a few developers. They expected that jbuilder have basically the same tradeoffs that normal erb view caching does, and it's surprising to find out that it does not.

[a14m]

BTW if anyone of you both @rwz and @vincentwoo wants to add the answer to the stackoverflow question and claim the bounty... be my guest...

+1 for adding the documentation

[vincentwoo]

Cool, I posted a long answer on SO: http://stackoverflow.com/questions/29190745/jbuilder-rails-caching-is-slower/29358844#29358844

[drobtravels]

Any thoughts on what would be the best approach to cache the JSON itself? I'm happy to put in a PR, but don't see a clear path forward.

Right now the entire Jbuilder is serialized to JSON at once with MultiJson.dump. If instead each nested Hash / Array was instead its own Jbuilder object, they could all be independently serialized (and cached), but the cached portion would always need to be nested under its own key.

It would be ideal if merge! could accept already serialized JSON but from some quick research I don't believe the common JSON serializers support mixing together Ruby objects with already serialized JSON.

[xinuc]

anyone working on this issue or any fork addressing this?

[rwz]

Not that I'm aware of. I keep this issue open to remind me to update README.

[drobtravels]

@xinuc Due to the current way jbuilder works it would likely require large changes (and possibly API changes) which is a problem due to the large adoption of jbuilder.

I think the best path forward would be creating a new gem focused on better caching. Feel free to reach out if you are interested in collaborating.

[rwz]

@droberts84 @xinuc I think the main problem is not Jbuilder, but the total absence of partial caching API for JSON.

[drobtravels]

@rzw What do you think about my approach mentioned above, and caching the JSON as an object in the cache store?

I would love to get this working with Jbuilder, and am happy to contribute. However, I currently have a use case which requires very large JSON structures that are often the same, so for best performance I need to create some sort of workaround for this issue.

[xinuc]

As far as I can understand, the underlying problem is the lack of mean to append a json string to the serializer. Please CMIIW.

a stupid hack I can think of is to parse the string and merge it again as a hash

json.something JSON.parse('{"some": "json string"}')

is there any better way we can achieve this?