Problem/Motivation

I was profiling a node with 49 products on it with Xhprof and noticed that the t() function was getting called a bunch. Further more it was inside commerce_product_field_extra_fields() that would get called for each product on that page. I have 5 or 6 product variations.

Proposed resolution

Static cache commerce_product_field_extra_fields().

Remaining tasks

User interface changes

API changes

Comments

joelpittet’s picture

Status: Active » Needs review
Issue tags: +Performance
StatusFileSize
new3.22 KB

Here's what I did for the performance boost. Any drawbacks?

rszrama’s picture

Title: commerce_product_field_extra_fields needs fast static, big performance gains » Use a static cache in commerce_product_field_extra_fields()
Category: Bug report » Feature request

Wow. I don't see any drawbacks here. Honestly, it seems like an issue that core would do well to optimize in general; it has a static cache for field info, why not for extra field info? Otherwise we're left having to implement our own static cache for every entity type. : P

That said, I'm not opposed to implemented the static cache here and simultaneously opening a core issue. I don't suppose you'd have a moment to search and see if someone's already working on a core fix?

joelpittet’s picture

This is the only one I could find #870292: hook_field_extra_fields() results should be cached by language that was similar but doesn't static cache and doesn't look like it caches... but the title says otherwise.

And this issue says it is cached... but I don't think it is:S
#730308-9: taxonomy_vocabulary_get_names() called on every field_attach_view()

fabianx’s picture

Depending how often this is called, might consider the drupal_static_fast pattern here instead.

I think it would make sense.

torgospizza’s picture

This patch seemed to have a positive effect on our performance as well. Any chance we can get it rolled in?

rszrama’s picture

Status: Needs review » Fixed

Guess I kinda lost track of this. Committed. : )

torgospizza’s picture

Thanks Ryan!

joelpittet’s picture

Thanks @rszrama.

@Fabianx I am curious to know where I can read up on the different between the two drupal static caching patterns? They look very similar and @dawehner tried to explain it but didn't quite sink in, the differences and when to use them.

fabianx’s picture

@joelpittet drupal static fast saves the function call to &drupal_static() basically.

It does so by using a static var that references the one retrieved from drupal_static.

Therefore drupal_static_reset still works, but it is still fast. Quite some reference trick!

I hope that helps.

joelpittet’s picture

Oh I think it's coming back to me thanks @Fabianx. It's intention is to reduce the # of function calls as well, specifically to drupal_static(). so in this case we wouldn't see 345 new calls to drupal_static(), just one call.

  // Save the function call statically.
  static $drupal_static_fast;
  if (!isset($drupal_static_fast)) {
    // Less calls to this drupal_static() function.
    $drupal_static_fast = &drupal_static(__FUNCTION__);
  }

  // Get our static data.
  $example_data = &$drupal_static_fast; 
  if (!isset($example_data)) {
    // Expensive calculation goes here..
    $example_data = example_data_load();
  } 

So although drupal_static() is cached and fast, not having to call it would be a bit faster if you have many calls. And in this case we have 300+ calls which could be significantly more...

Since I don't see a commit message on this issue, maybe it hasn't been committed and I can roll another patch for that @rszrama?

rszrama’s picture

I suppose I'm not opposed, but is it really necessary? We aren't using this pattern anywhere else, and I'm not sure how much performance impact we actually expect it to have relative to the other things that eat up time / memory in Commerce / Drupal 7.

joelpittet’s picture

It can be huge...

function with_static_fast() {
    // Save the function call statically.
  static $drupal_static_fast;
  if (!isset($drupal_static_fast)) {
    // Less calls to this drupal_static() function.
    $drupal_static_fast = &drupal_static(__FUNCTION__);
  }

 // Get our static data.
  $drupal_static = &$drupal_static_fast;
  if (!isset($drupal_static)) {
    // Expensive calculation goes here..
    $drupal_static = example_data_load();
  }
  return $drupal_static;
}

function without_static_fast() {
  $drupal_static = &drupal_static(__FUNCTION__);

   // Get our static data.
  if (!isset($drupal_static)) {
    // Expensive calculation goes here..
    $drupal_static = example_data_load();
  }
  return $drupal_static;
}

function example_data_load() {
  return ['loaded' => 'data'];
}

$START = time();
for ($i = 0; $i < 4000000; ++$i) {
  with_static_fast();
}
$END = time() - $START;
echo "With fast static took $END seconds\n";

$START = time();
for ($i = 0; $i < 4000000; ++$i) {
  with_static_fast();
}
$END = time() - $START;
echo "Without fast static took $END seconds\n";

Run the above in test.php
drush scr test.php
My results were 55 seconds vs 34 seconds.

But with an example even 100 times what we are dealing with here of 347 calls:


$START = microtime(TRUE);
for ($i = 0; $i < 34500; ++$i) {
  with_static_fast();
}
$END = microtime(TRUE) - $START;
echo "With fast static took $END seconds\n";

$START = microtime(TRUE);
for ($i = 0; $i < 34500; ++$i) {
  with_static_fast();
}
$END = microtime(TRUE) - $START;
echo "Without fast static took $END seconds\n";

With fast static took 0.3695080280304 seconds
Without fast static took 0.38044500350952 seconds

And with exactly 345 calls:

With fast static took 0.0026760101318359 seconds
Without fast static took 0.0027229785919189 seconds

So IMO, it's not completely necessary in this case but handy to know if the # calls is > 5000 it could have some nice savings.

rszrama’s picture

Hah, funny. I didn't catch what was going on at first, but it's interesting that we're now reverting to the pre-drupal_static() pattern of static caching. I mean, why even use drupal_static() at all in this case? You lose the benefit of being able to flush the static cache remotely, so we could just ditch it entirely, no?

joelpittet’s picture

@rszrama not sure I follow.

We should be using the &drupal_static. Just not a huge win on the fast drupal_static pattern unless there are a fairly large numbers of calls.

joelpittet’s picture

Status: Fixed » Needs review

@rszrama I downloaded -dev and it didn't have this patch applied so I'm moving back to NR.

rszrama’s picture

Status: Needs review » Fixed

It just wasn't pushed b/c I didn't see a bogus authentication error last time I tried a push.

What I was saying previously is just that the "new" pattern may as well bypass drupal_static() entirely and just use a local static variable. That's what we did before drupal_static() came along, but the rationale with an external static variable manager was that we'd be able to clear those caches from external scopes.

Not a big deal. Just pointing out how funny it is that we engineered our way to worse performance and have now invented a reverted pattern without just jettisoning the drupal_static() altogether. : P

joelpittet’s picture

@rszrama ah haha I see now. static -> drupal_static -> drupal_static + static. A bit over engineered yes but I guess like you and @Fabianx said we still can externally clear them out.

Thanks for committing this:) I've heard that bogus auth error happen to a few committers so far on push.

torgospizza’s picture

Oddly enough, after pushing this patch and getting a big surge of traffic last night, performance actually seems to be worse. Not sure if it has to do with us also using Memcache+Panels+Panelizer, but in the panels_render_display()'s call to field_info_extra_fields(), the commerce_product_reference implementation is now the slowest.

This is all coming from New Relic when viewing a Panelized node. I'll keep digging.

joelpittet’s picture

@torgosPizza looking at this patch I think it would be very unlikely to be this patch that caused the performance issue. It just caches the building of the extra form element building and all the extra calls to t() that were happening on every node view mode display.

Maybe the only way it could get worse (and maybe only by a few 5ms per node) is if the static cache was getting cleared all the time. (wild guess).

torgospizza’s picture

You might be right. It seems like Panels/CTools is making a lot of calls to field_info_extra_fields() so it could just be that our cache is broken. I have a few other outstanding patches related to Memcache performance, so I will check those. Thanks!

torgospizza’s picture

I was mistaken, it's the Product Reference's implementation of hook_field_extra_fields(). Looks like that module could use some static caching as well, so I created a new Issue: #2389573: Use a static cache in commerce_product_reference_field_extra_fields().

Status: Fixed » Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.