Magento

I investigated the performance issues with your web site and I found out that your PHP script loose a lot of time searching for two files named Data.php and Exception.php. In the end they find them but it looks to me like throwing darts. Here is one example:

lstat64("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code/local/Zend", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code/local/Zend/Locale", 0xbffeea0c) = -1 ENOENT (No such file or directory)
open("/home/webadmin/eshop.cosyplanet.be/html/app/code/local/Zend/Locale/Exception.php", O_RDONLY) = -1 ENOENT (No such file or directory)
time(NULL) = 1211431650
lstat64("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code/community", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code/community/Zend", 0xbffeea0c) = -1 ENOENT (No such file or directory)
open("/home/webadmin/eshop.cosyplanet.be/html/app/code/community/Zend/Locale/Exception.php", O_RDONLY) = -1 ENOENT (No such file or directory)
time(NULL) = 1211431650
lstat64("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code/core", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code/core/Zend", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/app/code/core/Zend/Locale", 0xbffeea0c) = -1 ENOENT (No such file or directory)
open("/home/webadmin/eshop.cosyplanet.be/html/app/code/core/Zend/Locale/Exception.php", O_RDONLY) = -1 ENOENT (No such file or directory)
time(NULL) = 1211431650
lstat64("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/lib", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/lib/Zend", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/lib/Zend/Locale", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/webadmin/eshop.cosyplanet.be/html/lib/Zend/Locale/Exception.php", {st_mode=S_IFREG|0644, st_size=1088, ...}) = 0
open("/home/webadmin/eshop.cosyplanet.be/html/lib/Zend/Locale/Exception.php", O_RDONLY) = 16

So in the end the file is found, but searching for it several times per request is not good at all for performance. Only during a checkout these two files were attempted to be found (and found several times, but the location was not cached or something that could help) for 2413 times:

-bash-3.1# egrep ‘Data.php|Exception.php’ /tmp/httpd.log | wc -l
2413
...so only the files, not also directory scans.

Does anyone has an idea how to solve this. Has someone alraedy been able to tackle this.

Thanks,
Geert

Hi all,

Is there really nobody who’s experiencing performance problems like me.
Any advise is welcome.

Thanks in advance,

Geert

Hi graes0,

I would like to reproduce this with my installation.
- How do you produce such a logfile like yours? Some apache config settings?
- You see that only when checking out, right?
- What magento version are you using?

Thanks,
Stefan.

Hi Stefan,

No I got this from my host. Brilliant service I can recommend them to everybody. Look at http://www.eapps.com. And they are cheap too. I got my own virtual server for only 80€ a year.
I don’t know how they produced this. I just asked them to check the activities on my server when loggin on, view a product add to a card, checkout. And it looks like this problem is for every action on my webshop.
I was wondering if somebody know how to put the files data.php and exception.php in the cache which would increase the performance a lot. At the moment the performance is really bad andunacceptable to go life.
I have the latest version installed.

Kind regards,
Geert

Hello Geert,

thanks for this info!
I have been able to reproduce this and took the freedom to file a bug report on your behalf:
http://www.magentocommerce.com/bug-tracking/issue?issue=2044

Now I don’t have a clue whether this is actually normal for a PHP application, but the comment by your web provider tells me that they don’t think so. Now we’ll have to wait and see.

Stefan.

Thanks Stefan,

That’s very nice of you. I really appreciate this. I also believe that this is not normal behaviour that a system has to run queries over and over again on a trial and error basis to locate a file and this for every response.
I really hope a solution is found soon.

Once more thanks,
Geert

It is possible that the problem here is with the concept of require_once and its usage in Zend Framework.

require_once may validate location of the file even if the class was already loaded, because include_path could have multiple locations this file might exist in, and because files with same filename in different locations could have different contents.

Zend Framework does not rely on autoload and uses require_once in every file.

Try removing / commenting out all require_once under lib/Zend, and see how it affects your performance.

I’m trying this right now, it’s possible there’s required instances.

Try removing only these:

Attached is the script to put in your magento root folder and run as:

replace_recursive.php  (File Size: 1KB - Downloads: 580)

@Moshe: Thank you for looking into this so fast! Gut feeling says you got that right. No time to try it out until next week, but will do.

Google turns up this issue numerous times among PHP wizards, and there is this PHP bug:
http://bugs.php.net/bug.php?id=43864

BTW, I am using APC 3.0.18 at my site.
There’s that apc.stat option since APC 3.0.10; setting apc.stat=0 seems to remove about 10% of the lstat64() calls.
Penalty is having to restart apache whenever the source code changes (ok for a production server).

Why don’t I examine existing wisdom before inventing my own???
http://prematureoptimization.org/blog/archives/33

@Geert: Try setting in your php.ini:
realpath_cache_size=1M (careful, this is per apache process)
realpath_cache_ttl=86400 (ok for production site)
This gets rid of maybe 30% of lstat64() calls with a “notable” speedup of my site.

@Moshe: Your script is for breakfast on Monday. Thanks and maybe take the weekend off!?

@moshe: I have experiemented with your script (commenting out lots of require_once statements). Success!!!

Setup:
- magento-1.0.19870 on my debian etch PHP 5.2.5 system.
- magento cache enabled.
- APC was off.
- realpath_cache were default settings (16k, ttl=180).
- Stopped apache, restarted with strace and then pressed the “add-to-cart” button on one of my products
- Used wc -l to count occurrences of lstat64 and fstat

Results:
- With lib/Zend in original state: lstat64 = 48,800 times, fstat = 6,600 times
- After running your script: lstat64 = 13 times, fstat = 400 times

YELLA! WHOPPA!

I have not conducted proper loading time measurements, but my site feels faster. When I click random products in my catalog, the loading time is now about 1 sec, where before it was more than 2 sec. I have tried to discount for “wishful thinking”.
This number also matches with the average time taken on my system for an lstat64() call (50-70 us), we seem to be saving 40,000 of those calls, hence we save 2 seconds!!!

I would like to know whether the same can be achieved by configuring a large realpath_cache_size and how this is affected by re-enabling APC, but this will have to wait (I’m busy for half the week).

@moshe:
Obvious question:
Is your lib/Zend code mod something that could go into a production system? If this change is really robust and has no bad side-effects with other config options or bytecode-caches like APC, I’ll certainly include this into my shop deployment script.
Please keep us updated about any progress you make or difficulties you run into. Glad to help in further testing, as time permits.

Thanks!
Stefan.

will try this tonight and update back on the results

I tried this out and am results are not encouraging for me ... please validate if the steps I followed are right - listing them here

Configuration:
PHP 5.2.5
Apache 2.2.8
MYSQL Distrib 5.0.22
APC off
Operating System : Centos 5
magento cache enabled

Steps:
Step 1: Had two browser instances of the same product details page open
Step 2: Logged in as root
Step3: Stop apache
service httpd stop
Step 4: restart apache with strace on
strace -f -o trace.txt /etc/rc.d/init.d/httpd start
Step 5: Click on Add to Cart on the page.
Step 6: Stop the trace
strace -f -o trace.txt /etc/rc.d/init.d/httpd stop
Step 7: Grep for checkout to find the apache child process handling this page request
grep checkout trace.txt
Step 8: grep for lstat and fstat
grep <apache process id> trace.txt | grep lstat | wc -l
grep <apache process id> trace.txt | grep fstat | wc -l

Before running Moshe’s script
lstat count = 59906
fstat count = 7906

After running Moshe’s script
lstat count = 38166
fstat count = 6391

Hope I was wrong somewhere in my steps .....and is the change that Moshe is suggesting a bug with Zend framework?

Moshe - 23 May 2008 10:57 AM

Attached is the script to put in your magento root folder and run as:

php -f replace_recursive.php

Please post back the results

I’ve just tried this, didn’t notice any real difference speed wise on my local server (XAMPP).

@salsasepp: thanks for the results
I do not see any problem with this change in bytecode cache environment.

@redpen: any difference if you add this to your xampp/apache/bin/php.ini as salsasepp suggested: