As debugging efforts continue, I think most of the community should expect we're going to be running a daily story on our effort to return the site to normality. We did another bugfix rollout to production to continue cleaning up error logs, and Paul I continue to make modifications to improve site performance. As you may have already noticed, we've managed a serious coup in the battle for low page times by replacing Linode's NodeBalancer product with a self-rolled nginx-frontend proxy. The vast majority of page loads are now sub-second.
Here's the quick list of stuff we changed over the weekend:
Rehash 15.05.3 - Changelog
Although we've yet to formally locate and disable the cause of the 500s and HASH(*) entries you sometimes get on page load, I now have a working theory on what's going on.
During debugging, I would notice we'd almost universally get a bad load from the cache if varnish or the loadbalancer burped for a moment, As best I can tell running backwards through traces and various error logs, the underlying cause of the 500s and bad page loads is one of two causes: either we're getting bad data from memcached on a cache read, or a bad load into cache from the database. Of these two, I'm leaning closer to the former, since if we were loading bad data into memcached, we'd see consistent 500s once the cache was corrupted.
It's somewhat difficult to accept that memcached is responsible for our corruption issues; we've been using it since golive a year and a half ago. However, given a lack of other leads, I flipped the memcached config switch to off, and then loadtested the site to see how bad the performance drop would be. Much to my surprise, the combination of query optimizations, the faster apache 2 codebase, and (for the most part) increased responsiveness due to having a multimaster database seems to be able to cover the slack for the time being. As of writing, memcached has been disabled for several hours, and I've yet to see any of the telltale signs of corruption in error_log. I also need to note that its the middle of the night for the vast majority of our users, so this may just be the calm before the storm.
I dislike using production as something of a guenna pig, but given the very transitory nature of this bug, and our inability to reliably reproduce it on our dev systems, we're left somewhere between a rock and a hard place. I would like to thank the SoylentNews community for their understanding over the last week, and I hope normality may finally return to this site :)
~ NCommander
(Score: 2, Funny) by Anonymous Coward on Monday June 08 2015, @10:26AM
Guinea my Pig and call me Cavy.
(Score: -1, Troll) by Anonymous Coward on Monday June 08 2015, @10:35AM
While N~Commander is blogging with crayon about the joys of toy construction by fitting Lego blocks together, who's finding the time to do the actual work?
(Score: 4, Funny) by Anonymous Coward on Monday June 08 2015, @11:29AM
While N~Commander is blogging with crayon about the joys of toy construction by fitting Lego blocks together, who's finding the time to do the actual work?
I am. I am Spartacode.
(Score: 4, Informative) by paulej72 on Monday June 08 2015, @11:09AM
One other lead we had with corruption is that the mod_perl memory gets corrupted. As part of the optimization rehash saves some vars into the working memory of the Apache thread. Since there are several Apache threads running at any given moment it is possible to cycle through ones that have a bad local cache of the data in memory. When moving over to Apache 2, we forgot to set the same configs that we had set in Apache 1 that prevented this from happening.
The two settings that we fixed were changing MaxClients to 15 from 150 to lower memory needs and MaxRequestsPerChild to 10000 from a default of unlimited. The latter change causes Apache to kill a thread once it has served 10000 requests and start a new one. This has the benefit of freeing the memory the thread uses and any corruption that may have happened.
As our corruption seems to happen more as time progressed, it seems like this may be the real fix for corruption issues. I was able to set this yesterday before NCommander turned off Memcache and what I saw in the logs was a vast improvement in the crap that was reported, although this was not conclusive as I did not have a chance to run it long enough to see what prolong use without a restart would do.
Team Leader for SN Development
(Score: 3, Informative) by sudo rm -rf on Monday June 08 2015, @12:53PM
Note I am no expert in server setups, but lowering MaxRequestsPerChild to 10000 seems quite reasonable to me. At the moment, when I load this page, my browser (Firefox) sends 18 requests (of which, btw, 17 result in a 304 not changed - very nice job there!), so killing and starting a new thread every 10000 requests will probably not affect end-user experience at all.
Also lowering MaxClients to 15 is a good idea, I think, given that the amount of response-data is pretty low (only a few KB worth of comments) and so the number of connections in the queue should be pretty low most of the time (because of fast processing of individual requests).
And lastly, if those two settings will solve the corruption problems - even better!
(Score: 3, Interesting) by kbahey on Monday June 08 2015, @02:26PM
If it helps, I see the 500 error occasionally. It happens when I am trying to moderate. Maybe once a day. When I retry things work (possibly because I am routed to a different server or Apache instance.
Lower that 10,000 even more. Maybe 2,000 to 3,000 or so. Apache will not be spawning new children that often even with such a lower number.
Also, regarding memcached disabled. Did the application use memcached for state information (so Apache/Perl instances on multiple machines can communicate/coordinate with each other)? If so, then is state info now in the database? If it does not affect performance then it is a moot point.
2bits.com, Inc: Drupal, WordPress, and LAMP performance tuning [2bits.com].
(Score: 2) by NCommander on Monday June 08 2015, @08:32PM
Has it happened since this article was posted? I've been keeping an eye on error_log since I woke up and haven't seen any of the taletell signs of data corruption we were seeing.
Still always moving
(Score: 2) by kbahey on Monday June 08 2015, @09:01PM
Yes, error_log will show the 500 error if it happens.
I have not seen the 500 error today.
2bits.com, Inc: Drupal, WordPress, and LAMP performance tuning [2bits.com].
(Score: 2) by NCommander on Monday June 08 2015, @09:11PM
Yeah, I think we found the cause of our corruption issue. Now we need to figure out why it is. My guess the problem is in Cache::Memcached::Fast, and not something we did as I think its unlikely the issue is with memcached itself.
Still always moving
(Score: 2) by kbahey on Monday June 08 2015, @09:28PM
Here is a guess: are you trying to large cache items? Perhaps you need to change the default from 1M to something more (using the -I [that is an uppercase "i"]).
2bits.com, Inc: Drupal, WordPress, and LAMP performance tuning [2bits.com].
(Score: 2) by NCommander on Monday June 08 2015, @10:01PM
We didn't change the configuration on memcached or any of the caching layer code on the upgrade. Generally what it does is a bunch of core functions such as getStory, getComments, or getUser tries to pull the data from memcache. If its not there, it runs a SELECT on the database to get it dynamically, and loads it into memcache for future loads. It's possible migrating from Perl 5.12 -> 5.20.1 broke the API though I have no idea how ...
Still always moving
(Score: 2) by FatPhil on Monday June 08 2015, @09:01PM
Great minds discuss ideas; average minds discuss events; small minds discuss people; the smallest discuss themselves
(Score: 2) by mendax on Monday June 08 2015, @07:19PM
Buggy code can be thought of as being an employment guarantee for programmers. The more bugs there are, the more programmers are needed to stomp them out. And since most bug fixes create other bugs, we have job security!
It's really quite a simple choice: Life, Death, or Los Angeles.
(Score: 0) by Anonymous Coward on Monday June 08 2015, @07:45PM
https://soylentnews.org/comments.pl?sid=7830&cid=193482 [soylentnews.org]
(OK
The server encountered an internal error or misconfiguration...)
Apologies for the silly language of the AC in question...
(Score: 0) by Anonymous Coward on Monday June 08 2015, @07:59PM
is the code for the new frontend proxy available to browse?
(Score: 3, Touché) by kaszz on Tuesday June 09 2015, @12:22AM
I get this in my inbox. The "Touché" becomes "Touché" where the "e" gets replaced by an "A" with a tilde above it and a "(c)" copyright sign after that. Like this:
"Re:How does the bacteria break free?, posted to Surfers Sought for Antibiotic-Resistant Bacteria Testing, has been moderated Touché (+1).
It is currently scored Touché (2). "