extends not performant when returning large datasets

[Altonymous]

When returning approx ~1400 records with only a few attributes, we discovered that using extends almost tripled the render time.

If we move the contents of base.rabl into index.rabl it goes from ~2.1 seconds to ~0.7 seconds to return the same results

https://gist.github.com/3638183

[databyte]

Make sure config.cache_sources = true if you're running benchmarks since the templates are read from disk when cache_sources is false.

Normally you use config.cache_sources = Rails.env != 'development' so that your templates will reload under development ... otherwise you'd have to restart the server everytime you made a template change :grin:

[mikesnare]

Thanks for that info. It's definitely quicker, but not as quick as when the contents of the extended template are just copied into the child template. Is that expected?

With the original, non cached, extended setup, the requests take about 2.1 seconds as Chris mentioned.

With the extended setup with the cache enabled, it hovers around 1.1 seconds -- definitely an improvement.

When we just copy the code from the parent template into the child template directly and remove the "extends" call it's .7 seconds. ~40% improvement seems worth pursuing. Any other suggestions?

[databyte]

I have a feeling that on the micro benchmark level, there's not a huge part of the performance stuck in reading the template file - most of that 1 second savings was probably with caching.

There's not much you can do to speed up reading a file's contents, evaluating it and then inserting the results back into a hash.

I, personally, haven't had anything near a second of response times nor have I seen such a big difference between using one template or combining multiple. The same thing would be a problem with ERBs too when using partials.

I don't see why there would be a ~40% performance hit in simply pulling in some template code or why the call takes more than 20ms overall. If you gave it a dummy object (that doesn't hit the DB like OpenStruct.new) and a super simple template, you should see much smaller numbers.

Maybe it's an environment issue? Something in the controller? Is it a super large object?

If you find something... I do accept pull requests!

[Altonymous]

To be clear we are doing this in Rails 3.2.6 using ActiveRecord w/ a mysql database.

When breaking down the performance we are able to see that the majority of time spent is in rendering the rabl template. I tried reproducing this issue with standard objects in your test suite and they rendered VERY quickly. However, when I did the same tests under fixtures for Rails it took a much longer time.

Essentially all I did to test it was to define a method that created 2000 users with phone numbers and then called the route. I then debugged to see where the time sink was and it was in rendering the rabl template.

[databyte]

In Rails when it says that the view took n seconds - it also means accessing the objects and any lazy loading of objects referenced in the views is a portion of those n seconds.

Started GET "/users.json" for 127.0.0.1 at 2012-09-05 14:19:03 -0400
Connecting to database specified by database.yml
Processing by UsersController#index as JSON
  Parameters: {"user"=>{}}
  User Load (1.0ms)  SELECT "users".* FROM "users" ORDER BY username ASC
  PhoneNumber Load (0.1ms)  SELECT "phone_numbers".* FROM "phone_numbers" WHERE "phone_numbers"."user_id" = 1
  Rendered users/index.json.rabl (24.8ms)
Completed 200 OK in 43ms (Views: 32.9ms | ActiveRecord: 1.4ms)

The 24.8ms there doesn't include my User.find from the controller but it does include the PhoneNumber call because I didn't eager load in phone_numbers on the original AR call within the controller. I've seen the "rendered" times increase when a single attribute is added which in turns does some horrible in-memory shuffling or hits another DB call.

So think of it less as "RABL is slow" (though that could still be the case and pull requests are welcome) but more along the lines of what's in my template that could be slow.

The actual time spent in the controller and database is a bulk of that time, not actually RABL itself. It's like ERB isn't slow but everything you're accessing while in ERB is slow.

[Altonymous]

Our case doesn't actually have nested children.

To boil this issue down into it's simplest form...

base.rabl - This rabl file has the base attributes on an account. index.rabl - All this does is simply extends base.rabl

The idea being that we were trying to only have the information we needed and we removed any nested objects so they wouldn't be a factor.

Examples:

Case #1 with extends

base.rabl

attribute :id attribute :name attribute :status attribute :uuid

index.rabl

collection @accounts extends 'accounts/base'

Result

http://d.pr/i/vLAo

Case #2 without extends

index.rabl

collection @accounts attribute :id attribute :name attribute :status attribute :uuid

Result

http://d.pr/i/pvVH

[Altonymous]

I should also note this is with

config.cache_sources = true

Rails server was restarted after the config change

[shmeltex]

I'm seeing the same behavior - rendering without extends is faster and significantly faster if collection size is large. In my test for 1,000 elements about 50% faster, for 10,000 about twice faster.

[databyte]

Ah, I missed the fact that it was a large collection - I just reread the original post. I'll dig into it (not that I wasn't, I still was).

[nesquena]

This issue is an extension of this older issue: https://github.com/nesquena/rabl/issues/167. I am aware that 'extends' especially can be quite slow (when compared to those templates without extends), although this can be mitigated heavily through utilizing caching (both sources but also using the included template caching).

The issue I think that causes this slowness with extends (and partial) is the need to construct a new engine. For those curious and my later reference, here is the implementation for extends:

https://github.com/nesquena/rabl/blob/master/lib/rabl/builder.rb#L112:

# Extends an existing rabl template with additional attributes in the block
# extends("users/show") { attribute :full_name }
def extends(file, options={}, &block)
  options = @options.slice(:child_root).merge(:object => @_object).merge(options)
  result = self.partial(file, options, &block)
  @_result.merge!(result) if result
end

Notice this basically just utilizes partial and merges the result. partial is defined here:

https://github.com/nesquena/rabl/blob/master/lib/rabl/partials.rb#L9

and utilizes object_to_hash which takes any object and a template and returns the result as a hash. Doing this currently requires instantiating an entirely new engine:

https://github.com/nesquena/rabl/blob/master/lib/rabl/partials.rb#L27

Rabl::Engine.new(options[:source], engine_options).render(@_scope, :object => object, &block)

which means that any Engine (template) with an extends has to instantiate a newEngine per extends per object without caching enabled. With sources cached and of course with templates cached, this is of course partially mitigated.

I am very interested in continuing to speed up RABL and hope that we have more time to spend on this in the near future. If anyone has any ideas or suggestions, I welcome the feedback.

I will say though that in most usage, and I have many production apps using rabl, with caching of sources and templates, even complicated extends with complex attribute and nodes (or extends multiple levels deep) tends to be quite fast when rendering a 'small' set of items (< 100). In most of my cases, I rarely need to render more then a hundred items, in those cases I tend to use pagination. That said, I would like RABL to scale to rendering 1000+ items better in the future.

[ccocchi]

The problem with extends is that you MUST re-evaluate the template source for each object, because you have many cases where you need to replace the variable by the actual value in order to evaluate things like if, node(@post), ... I think that's the main reason why extends is slow.

@Altonymous if you really want performance with extends and 100 objects, I developped another gem to render RABL files, which tends to be faster (2x with extends) because templates are evaluated only once. Or you can try pagination like @nesquena suggested ;)