We upgraded the servers at NeatoShop.com and Neatorama.com a couple of weeks ago, and in the past week we started noticing and receiving reports that on “some” page loads there was a 30-second delay where the page seemed to hang before finally returning any content.
The common things we could put a finger on were 1) it would seem to happen with a raw/initial page load (e.g., in a brand new incognito window), 2) it would not hang up anymore after that first page load, and 3) it seemed to happen only if we loaded neatoshop.com which was then redirected to www.neatoshop.com.
It took a ton of code profiling and countless attempts to reproduce the problem (because it didn’t happen for me on every new incognito page load), but I finally traced the delay down to session_start(). This didn’t really make sense to me because we’ve used php5-memcache (obviously with Memcached) for handling sessions with redundancy across our 7 web servers, and nothing regarding sessions nor Memcached changed on our end any time recently. So what could the problem be?
It started to seem like a pointless shot in the dark to keep googling for clues, but something that stuck out in my mind were reports of session files getting locked if there were two simultaneous requests from the same user. This didn’t seem to apply since we’re dealing with Memcached sessions and not file-based sessions, but then I noticed the new memcache.lock_timeout option in php5-memcache v3.0.4 which has a default value of 15 seconds.
Hmm… 15 seconds with a lock on two simultaneous requests seems like it could result in a 30 second delay… ya think? There’s one way to find out.
I tried changing the memcache.lock_timeout value to 2 seconds then trying to repro the problem. Once it seemed like I got the hang-up to occur, I held my breath and the page hung for 4 seconds before loading. Then I changed the value to 1 second and tried again, and as I’d hoped, the loading time was 2 seconds!
Finally, I’ve reduced the value to 0 seconds and there seems to no longer be any delay. I’m not certain of any side effects or unintended consequences of setting the value to zero, but whatever they are, they are insignificant as compared to every customer on an e-commerce site occasionally being subjected to a 30-second delay. I just thought I should share this tale of woe, as I couldn’t really find any good info on it, and I’m assuming there must be others facing the same issue.
Update!
After reducing the value to zero, I started getting reports of slow load times again, which indicates a value of zero is not valid because it causes the default of 15 seconds to be used. So we’re stuck using a 1-second lock_timeout, which is the only acceptable solution, but a 2-second delay is much better than 30 seconds!