Hi all,
We have a fairly complex site for a corporate client. We are in the process of undergoing performance testing, which is being performed by the client's internal QA team. Overall the results are satisfactory: with 100 concurrent users on the site (50 logged in), most pages are returning in an average of under 1 second, with a few outliers. The site is being tested on the client server, to which we have no direct access at the moment.
Here's the problem we could use some ideas troubleshooting.
We are using content profile for users profiles.
When the content profile node is updated/saved, the response times (from firebug) look like this:
Post 479ms
Get 20.5S
but sometimes we see it like this:
Post 17.6
Get 3.9s
This is not under load, but the times are about the same when under load.
On our dev server, this same page seems a little slow, but nothing at all like this.
From what I can tell, the lag doesn't seem to come from the Drupal stack: Executed 184 queries in 273.09 milliseconds. Page execution time was 764.87 ms. Rather it seems to come before it or after it.
Has anyone seen anything similar or otherwise have any suggestions for troubleshooting? Thanks in advance.
Comments
profiling required
Did you try to make profile with XDebug? - it can show where your execution time is going.
By myself with content profile I have slow queries only. Two queries with up to 2sec execution time.
Cache clearing?
Do you have caching on on this site? If so, then it could be that clearing the cache after posting a node.
See if you have cache lifetime configured in admin/settings/performance, and increase it.
If you are using normal core caching, then you can check the cache_* tables before and after a post and see if it had something before but not after. Switch to memcache and see if that overhead goes down a bit.
Also check the option in devel to show the stats before the redirect, and it will give you a clue on what queries run when you post, before you are redirected to the GET.
Drupal performance tuning, development, customization and consulting: 2bits.com, Inc..
Personal blog: Baheyeldin.com.
This is most likely due to
This is most likely due to table locks. You need to convert all your tables from MyISAM to Innodb.
The option in devel to show
The option in devel to show the stats before the redirect was helpful. Thanks for that tip. I can see that the lag is definately coming from Drupal, although ot from queries.
It's not caching-related as it happens regardless of whether caching is on or off or what the cache lifetime is set to.
Unfortunately I can't set up xdebug on the server in question (nor can I install memcache yet), but we're looking at it with xdebug on our staging server to look for clues.
DLC Solutions
EthosCE
Do you contact other sites? Or email stuff?
Check for network connections done from your across the internet. If your site is configured to contact other sites (e.g. to inform them of new content, ...etc.), or to email lots of stuff to users, then these can add a lot of burden on the site. If it is email, then check the http://drupal.org/project/queue_mail module which defers sending to cron time.
Also, views queries may not show on devel's output. You need to enable the option under Tools in views that make queries show up in devel, with their timing. Although it is unlikely that you have views there that you don't have elsewhere, it will show you queries from views.
Drupal performance tuning, development, customization and consulting: 2bits.com, Inc..
Personal blog: Baheyeldin.com.
So we solved the problem. We
So we solved the problem.
We had a "orphaned" action that seemed to be causing the problem. It was an action from a custom module that would send an email when a content profile was created or upated.
At some point before the performance testing, the action was deleted (using the UI) so the recipient wouldn't get bombarded with emails from the testing. We think it was deleted before it was unassigned from the trigger. It didn't actually delete though, and still seem to be getting called. However no email was sent. It just hung and then timed out. We deleted it using actions_delete and then things returned to normal.
Oddly enough, we can't seem to reproduce this, even when we re-add/delete the action. When the action is added back in and assigned to a trigger it works fine, and I couldn't find the combination of steps to return it to the orphaned state.
Alexandr, thanks for the suggestion about xDebug. We used it to step through every module until we found the suspect function. Khalid, thanks for your help. The email suggestion turned out to be correct. Your contributions to this group are a great help!
DLC Solutions
EthosCE
Install mytop and run it
Install mytop and run it while they are loading the website. You can see the wait time for each query or insert.