Utoxin's Random Insanity

Now that I’ve had a day or so to recover, I’m going to tell you about what I just spent 2-3 weeks trying to resolve. By way of explanation, our main product at work is a CakePHP based CMS application. It has a lot of neat features, including the ability for users to upgrade to newer versions any time they choose. We keep all versions present in /etc/precious_core/<version_number>/, and each user has a symlink to the relevant directory in their webroot.

When they upgrade, part of the process is to replace that symlink with a new on that points at their new version. For a long time we’ve known there was a problem of some kind related to CakePHP’s cache that developed after upgrades, but it was never a huge problem, so we mostly just ignored it. However, in a recent release, it started causing major problems, and I got tasked with finding and fixing the actual bug. I figured it would take a day or two, and I’d be done with it. Little did I know just how painful this was going to be.

I initially tried several ways of forcing the cache to get cleared when the app was upgraded. That worked well, as far as it went, but then a new problem surfaced. At least half the time, the cache would re-populate with bad data after an upgrade. Some of the cached file paths would be for the wrong version of the central app, for no apparent reason. I tried throwing even more thorough cache clearing at it. Things got a little better, but it still wasn’t working.

Finally, I fully duplicated our production setup on my local dev machine, parallel version directories included, and installed a PHP debugger, so I could step through the code and figure out what exactly was going on. After several hours of research, I determined that the error was happening in this function:

function __map($file, $name, $type, $plugin) {
	if ($plugin) {
		$this->__map['Plugin'][$plugin][$type][$name] = realpath($file);
	} else {
		$this->__map[$type][$name] = realpath($file);
	}
}

The file paths that were getting inserted into $this->__map were sometimes incorrect. I knew that realpath() could cache it’s data, but I was explicitly calling clearpathcache() during the upgrade process. So why was it getting bad paths sometimes? At this point, Ceeram (@ceeram) of #cakephp on Freenode helped me out by pointing me at this blog: PHP, symlinks, and the realpath cache, which explained perfectly what was going on.

It turns out realpath()’s cache is per-thread, so even though I was clearing it in the apache thread that was doing the upgrade, it still had old data in other apache threads. Possibly very old data sometimes. (I once saw file paths for 3 different versions of our app in one cake_core_file_map during testing.) The simplest solution that I was able to discover was to simply add an apache graceful restart during our upgrade process. The impact of a graceful restart is minimal, but it does cause all apache threads to get closed down and new ones opened, which fixes the problem by forcing all of them to clear their cache.

So, the moral of the story? Well, not sure there is one. Except that sometimes you need a breakpoint debugger even when you’re coding PHP.