New Relic shows the token hook being called a lot I've just installed NewRelic on a Drupal 7 website, and I'm now going through the most obvious issues that jump out at me.

Looking at the Drupal specific menu items, I notice the "Token" module accounts for about 1 min active time in 30 minutes clock time. 

The list of hooks shows the "tokens" hook accounting for 203 seconds, which is about 80% of the total time. Each call takes less than 0.02ms, but the hook gets called over 18 million times in 30 minutes clock time. The closest one is node_view with 500 thousand calls. That seems more reasonable. 

I can't, right off the bat, find a way to dig into the call tree for the Drupal hooks.

My questions:


Does the amount of calls to the tokens hook seem normal?
Is there a way in New Relic to find out where most hook invokes originate?
I wrote a tiny module to log all calls to the tokens hook, so that I'd have some sort of idea where the tokens were coming from:

&lt;?php

function token_logger_tokens($type, $tokens, array $data = array(), array $options = array()) {
  watchdog('token_logger', print_r($tokens, TRUE), array());
  // Activate to fill up your database fast!
  // watchdog('token_logger', print_r(debug_backtrace(FALSE, 20), TRUE), array());
}


Turns out this was mostly the file_entity module running image alt en title tags through tokens, so that they could be overridden with another pattern if so desired:

// file_entity.file.inc:279

$alt = variable_get('file_entity_alt', '[file:field_file_image_alt_text]');
$title = variable_get('file_entity_title', '[file:field_file_image_title_text]');
// a little further down the line in a loop
$output = token_replace($alt, array('file' =&gt; $file), $replace_options);
// a little further still
$output = token_replace($title, array('file' =&gt; $file), $replace_options);


That adds up to 2 calls to the token hook per file loaded. If you have a busy website with a fair amount of images, it adds up quickly. About 800 calls each time the homepage is loaded, specifically.

I think I'll patch the file_entity module to cut out tokens for the default option, and verify it makes a difference speed-wise.