Speeding up PHP

Events happening in the community are now at Drupal community events on www.drupal.org.
huesforalice's picture

We're currently porting a community site from tikiwiki to Drupal. We have around 4000 registered users. Usually there are about 150-300 people online, with about a 10th being authenticated or so (this figure will probably rise, as Drupal has the option of keeping people logged in which the current Tikiwiki installation hasn't).

I'm going to keep anonymous users away from cpu and ram by using authcache + apc. My problem at the moment is, that page generation times are rather slow. If I request a simple page, generation time is around 650ms, on views often up to 1,5s (this tested on my windows machine, quadcore, 5gb ram, no other users on the apache/mysql). I did some benchmarking and discovered that only around 50-100ms are spent doing sql queries, the rest seems to be pure php execution time. I have tried zend optimizer and apc to bring that down, but zend doesn't seem to impact at all, and apc brings about 100ms. I have actually seen a Zend white paper where they claim speed gains of 350% on Drupal?

My questions basically are: Is it normal that php execution time is 6 times the time spent on queries? And what do you suggest doing to bring down this time so say 200ms (which I would find acceptable).

I do have a massive amount of modules at work here, with the top cpu consumers being lucene api and cck.

Thanks for your ideas.

Comments

Replies

kbahey's picture

10th of 300 is 30, and that is certainly doable on a Drupal site. Even up to 200 is fairly easy if the site is not heavy, and well tuned. So that part is not an issue.

Authcache is for logged in users, not for anonymous users. For anonymous users you can either use Varnish with Pressflow, or just memcache, which works wonders when page caching is enabled.

650 ms total page execution is not unreasonable for a Drupal site.

High PHP time can mean various things. Lots of modules is certainly part of it. The more you have the more file system accesses per page load and that eats up time.

Another reason is excessive theming functions for renderning views that do node_load() and user_load() individually.

Another is that you have modules that request stuff over the network (e.g. tweets, ...etc.)

Use a profiler such as xdebug or xhprof to profile your page and see where the time is spent.

Drupal performance tuning, development, customization and consulting: 2bits.com, Inc..
Personal blog: Baheyeldin.com.

Authcache & Anonymous users

Jonah Ellison's picture

Actually, Authcache is for both anonymous and authenticated users. It does offer some advantages over Drupal core and the Memcache API module, such as implementing page_cache_fastpath() to avoid establishing a database connection when serving pages from the cache.

Thank you for your answers. I

huesforalice's picture

Thank you for your answers. I use authcache for caching because, like Jonah says, I have better control over the caching mechanism. In my case I like to specify which paths should be cached and which not, and also I can avoid hitting the database almost completely. if I use the apc cache. Authcache also has a nifty ajaxrequest function which enables certain modules to transfer uncached data after the page has already been transferred and built. Afaik if I use varnish, I'm not able to log access statistics, which I need for this project.

kbahey thanks for pointing me to xdebug and xhprof, I'll check them out and will be back with a report on how things went.

The only thing I'm wondering about is, why the code caching of apc and zend doesn't really bring much advantage. Is that generally so? Or how would be a way to find out if this is actually working?

how many nodes and facets you

ddorian's picture

how many nodes and facets you have in lucene_api? i think it was designed to 10k nodes (max) check that out and offload it maybe to solr

that doesn't seem to be the

huesforalice's picture

that doesn't seem to be the problem. What is a performance issue though is, that Lucene API spends 100ms (when profiling) on hook_init doing stuff it doesn't always need. I've already requested to make Lucene API only load Zend components etc. on a search or index update, haven't had an answer though. I have already done some customization to the search on our site, so I'm trying to stay with Lucene for now. But possibly solr would be a good bet too.

jcchapster's picture

I am speculating that this will solve the issue you spoke of.

Taken from: http://varnish-cache.org/browser/trunk/varnish-cache/doc/sphinx/faq/inde...

=== How can I log the client IP address on the backend? ===
All I see is the IP address of the varnish server. How can I log the client IP address?
We will need to add the IP address to a header used for the backend request, and configure the backend to log the content of this header instead of the address of the connecting client (which is the varnish server).
Varnish configuration:
{{{
sub vcl_recv {
# Add a unique header containing the client address
remove req.http.X-Forwarded-For;
set req.http.X-Forwarded-For = client.ip;
# [...]
}

nestor.mata's picture

Besides telling varnish to send the original IP in the X-Forwarded-For header, you also need to tell Drupal and optionally Apache to pull the IP from this header.

In Apache:
In a usual apache configuration file you would see this comment before setting the LogFormat:

# The following directives define some format nicknames for use with
# a CustomLog directive (see below).
# If you are behind a reverse proxy, you might want to change %h into %{X-Forwarded-For}i

So you would replace something like this:
LogFormat "%h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" combined
For something like this, for example:
LogFormat "%{X-Forwarded-For}i %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" combined

In Drupal:
In the site settings.php file you will need to uncomment the configuration for reverse proxy:
'reverse_proxy' => TRUE,
And as a recommendation you should also uncomment and set the ip address(es) of your varnish server here:
'reverse_proxy_addresses' => array('127.0.0.1'),

The modification in the apache.conf file would allow you to use that IP in the access log file, and the drupal site settings.php will tell drupal to use that IP for everything.

~Nestor

"Is it normal that php

dalin's picture

"Is it normal that php execution time is 6 times the time spent on queries?"

Yes, and that's largely by design. It's relatively easy to scale web servers (basically just add more of them as needed). It's relatively more difficult to scale database servers (You start with master-slave replication, maybe master-master, but moving up from there gets difficult).

"I did some benchmarking and discovered that only around 50-100ms are spent doing sql queries, the rest seems to be pure php execution time."

If you found that number via the Devel module's query output, know that any queries generated by Views are not included. You must enable Views query statistics separately on the Views "Tools" tab. And you may be creating queries via Views for which the default DB indexes are not helping (which definitely sounds the case if a Views page is taking 1.5s). If you don't have a background in tuning indexes take a look at the DB Tuner module for some quick and easy assistance.

Assuming that you haven't overeaten at the module buffet, and that you aren't cramming tonnes of information on every page, then the performance goals that you are aiming for sound reasonable. It may just be a matter of getting some good familiarity with the performance tools available.

--


Dave Hansen-Lange
Director of Technical Strategy, Advomatic.com
Pronouns: he/him/his

Thanks for pointing out the

huesforalice's picture

Thanks for pointing out the extra query switch in views, I wasn't aware of that, but I was actually missing the views query in the query log. I have already added a few indexes especially on the urls_alias table, as this gets accessed quite a lot. I'll look into the db tuner and see if I can make us of it.

Using xdebug I've also found that Drupal spends a massive amount of time loading and initializing the modules. I've developed a number of custom modules and coming from a oop background decided to split code up into several modules instead of putting related stuff into one big module. Seems this is the wrong approach for drupal, so I'll probably refactor some of those as well.

Generally include_once seems to cost quite a few cycles.

The "massive amount of time"

moshe weitzman's picture

The "massive amount of time" in include_once indicates that your APC is not working. Perhaps you disabled it to run xdebug or xhprof. You will find very little time here when APC is properly functioning.

So include_once makes php

huesforalice's picture

So include_once makes php compile the included file if there is no cache, right? Is there any way I can be sure that APC is running, like cache files being generated etc? It does show up in the php.info, but I'm not sure I got all the settings right.

In the source directory for

Jamie Holly's picture

In the source directory for APC, there should be an apc.php file (if not just go to the pecl file and download/extract the package for your version of APC and grab the file out of there). Upload it to your server and pull it up in a browser. It has to be on the same hostname as the main site, but there are password protection options you can configure in the file. Then you can look at that and see what all is being cached.


HollyIT - Grab the Netbeans Drupal Development Tool at GitHub.

Good APC article by 2bits

recrit's picture

The article below might help in your troubleshooting. It details possible issues that can cause high php execution time.

http://2bits.com/articles/high-php-execution-times-drupal-and-tuning-apc...

One new finding: I have

huesforalice's picture

One new finding: I have tested the site on a Macbook Pro with Core i5 CPU using MAMP in it's standard config (only giving php 128MB of RAM) and using PHP 5.3 + XCache. Now I'm at around 100ms on first call and even less as soon as the query cache kicks in. Seems like a) PHP 5.3+XCache does the trick or b) our current webserver is grossly misconfigured. We'll have a new server soon that I have full access to, and I'll let you know what we did in the end.

High performance

Group notifications

This group offers an RSS feed. Or subscribe to these personalized, sitewide feeds: