I went to Drupal 7.33 and all I got was a slow site
So, you just upgraded your site(s) to Drupal >= 7.33, everything seemed fine in your tests. You deployed the new release and after a while you notice that your site isn't as fast as before. It's actually slowing down everything on your server. You started Googling and ended up on this blogpost.
Sounds like your story? Read on!
I spent the last 2 hours figuring this out, I decided it would be best to write it up right away while it's fresh in my memory. TLDR; at the bottom of this post.
We did an upgrade to Drupal 7.34 recently, we thought everything was fine. Release went over 3 different environments before deploying to live and no actual issues were found.
After deployment to live, we got some reports that the site was responding slow. We didn't directly link it to the upgrade to 7.34, I actually did a diff between 7.32 and 7.34 to see what changed after these reports and did not see anything suspicious that could cause this.
We had to investigate after a while as there was no sign of improvement, the CPU of the server was hitting 100% 24/7. New Relic monitoring told us about many calls to the "file_scan_directory" function of Drupal. When I actually logged the calls with the following snippet:
static $count;<br>if (!isset($count)) {<br> $count = 0;<br>}<br>$count++;<br>drupal_debug($count . PHP_EOL);
The count actually went up to 700 for every request (It's quite a large project, plus the file_scan_directory is recursive).When I printed the "debug_backtrace", I saw that this call was coming from "drupal_get_filename".Looking at the function arguments, Drupal was looking for a imagecache_actions file, why?! And why on every request? Doesn't it cache these records in the registry?!
Yes it does! It appeared the imagecache_actions module had a typo in it (patch here):
module_load_include('inc', 'imagcache_actions', 'image_overlay.inc');
This should be:
module_load_include('inc', 'imagecache_actions', 'image_overlay.inc');
This would not have been an issue previously, 7.33 introduced a change though.Pre 7.33:
$file = db_query("SELECT filename FROM {system} WHERE name = :name AND type = :type", array(':name' => $name, ':type' => $type))->fetchField();<br>if (file_exists(DRUPAL_ROOT . '/' . $file)) {<br> $files[$type][$name] = $file;<br>}
7.33 or higher:
$file = db_query("SELECT filename FROM {system} WHERE name = :name AND type = :type", array(':name' => $name, ':type' => $type))->fetchField();<br>if ($file !== FALSE && file_exists(DRUPAL_ROOT . '/' . $file)) {<br> $files[$type][$name] = $file;<br>}
Before 7.33, Drupal would try to find the record in the system table, it wouldn't find it and the $file would be NULL. The resulting string would be "DRUPAL_ROOT . '/' . $file", as $file is NULL, you can also see it as "DRUPAL_ROOT . '/'". Obviously the DRUPAL_ROOT exists, so it returns TRUE. It would put the record in the $files array and continue with what it was doing.
Because 7.33 and higher does a NULL-check on $file, it will not add any record to the $files array. This causes it to go into the file discovery routine:
if (!isset($files[$type][$name])) {<br> // ... Some code<br> $matches = drupal_system_listing("/^" . DRUPAL_PHP_FUNCTION_PATTERN . "\.$extension$/", $dir, 'name', 0);<br> foreach ($matches as $matched_name => $file) {<br> $files[$type][$matched_name] = $file->uri;<br> }<br>}
This code will try to scan your Drupal installation for the given file. It will not find the file and continue eventually, but it will execute the file search in EVERY request that you execute the module_load_include.
While our issue was in the imagecache_actions module, your issue might be in any module (even custom) which does a wrong module_load_include.It's very hard to find this out yourself. You can edit includes/bootstrap.inc on line 866 to write some info away to /tmp/drupal_debug.txt:Add the following code after line 866:
else {<br> drupal_debug('Missing file ' . $type . ' ' . $name . ' ' . DRUPAL_ROOT . '/' . $file . PHP_EOL);<br>}
TLDR; an issue in imagecache_actions combined with an upgrade to Drupal >= 7.33 killed the performance of our site. Patch for imagecache_actions here. Causing issue/patch here.