PressCrew / infinity

A WordPress theming engine
http://infinity.presscrew.com
GNU General Public License v2.0
40 stars 14 forks source link

Incredible slow #18

Closed unsalkorkmaz closed 12 years ago

unsalkorkmaz commented 12 years ago

Hi, For some reason infinity or child themes are incredible slow compared to other themes..

Twenty Eleven theme results:

Total Load Time:    1.0230seconds avg.
Site Load Time  0.6021seconds avg.
Profile Overhead:   0.4209seconds avg.
Plugin Load Time:   0.4395seconds avg.
Theme Load Time:    0.0228seconds avg.
Core Load Time:     0.1266seconds avg.
Margin of Error:    0.0131seconds avg.
(1.0230 observed, 1.0099 expected)
Visits:     4
Number of PHP ticks:    10,735 calls avg.
Memory Usage:   55.69 MB avg.
MySQL Queries:  17 queries avg.

Infinity Theme Results:

Total Load Time:    8.0002seconds avg.
Site Load Time  2.0337seconds avg.
Profile Overhead:   5.9665seconds avg.
Plugin Load Time:   0.4791seconds avg.
Theme Load Time:    1.2179seconds avg.
Core Load Time:     0.1422seconds avg.
Margin of Error:    0.1945seconds avg.
(8.0002 observed, 7.8057 expected)
Visits:     4
Number of PHP ticks:    11,919 calls avg.
Memory Usage:   66.63 MB avg.
MySQL Queries:  20 queries avg.

Infinity Skeleton Child Theme results:

Total Load Time:    8.1542seconds avg.
Site Load Time  2.0769seconds avg.
Profile Overhead:   6.0773seconds avg.
Plugin Load Time:   0.4813seconds avg.
Theme Load Time:    1.2609seconds avg.
Core Load Time:     0.1371seconds avg.
Margin of Error:    0.1976seconds avg.
(8.1542 observed, 7.9566 expected)
Visits:     4
Number of PHP ticks:    11,850 calls avg.
Memory Usage:   67.00 MB avg.
MySQL Queries:  19 queries avg.

Used http://wordpress.org/extend/plugins/p3-profiler/ for profiling

Is there any way to increase performance?

MrMaz commented 12 years ago

Please provide a lot more info on this ticket, like Infinity version, how many child themes, etc. Its going to be impossible to debug your set up without having all of the info and the actual theme files.

MrMaz commented 12 years ago

BTW, the profiler overhead number is big. You are supposed to take that number out of the final result. Lots of calls != slow.

unsalkorkmaz commented 12 years ago

I am not sure if that measures are wrong, i am just trying to identify slowness on my site. For more fair results, i install default wp on same server with a free domain: http://korkmaz.biz

First test - Default WP, 0 plugin, No multisite, 0 theme: Theme is twenty eleven by default:

Total Load Time:    0.1770seconds avg.
Site Load Time  0.0846seconds avg.
Profile Overhead:   0.0924seconds avg.
Plugin Load Time:   0.0054seconds avg.
Theme Load Time:    0.0124seconds avg.
Core Load Time:     0.0742seconds avg.
Margin of Error:    -0.0073seconds avg.
(0.1770 observed, 0.1843 expected)
Visits:     8
Number of PHP ticks:    36 calls avg.
Memory Usage:   13.69 MB avg.
MySQL Queries:  35 queries avg.

Pingdom load: http://tools.pingdom.com/fpt/#!/pWTuH1lpl/korkmaz.biz 70ms for html

Second test - Default WP, 0 Plugin, No multisite, 1 theme: Infinity theme with buddypress brunch

PressCrew-infinity-buddypress-1.0b3-22-gf75b24d.zip

Total Load Time:    6.9370seconds avg.
Site Load Time  1.3846seconds avg.
Profile Overhead:   5.5524seconds avg.
Plugin Load Time:   0.0057seconds avg.
Theme Load Time:    1.1276seconds avg.
Core Load Time:     0.1265seconds avg.
Margin of Error:    0.1249seconds avg.
(6.9370 observed, 6.8121 expected)
Visits:     8
Number of PHP ticks:    72 calls avg.
Memory Usage:   23.63 MB avg.
MySQL Queries:  29 queries avg.

Pingdom load: http://tools.pingdom.com/fpt/#!/nQIrmg3e9/korkmaz.biz 246 ms for html

MrMaz commented 12 years ago

You should run a test with the WP + BP using default theme. Have you figured out that the "Total Load Time" is not what you should be looking at?

unsalkorkmaz commented 12 years ago

First byte is important for me. Infinity: http://www.webpagetest.org/result/120615_EF_XQE/ 0.407s First byte. Its default wp with 0 plugin and only Infinity theme. Twenty Eleven: http://www.webpagetest.org/result/120615_SH_XRS/ 0.240s First Byte.

With lots of plugin / images etc first page loading time is gonna really much. And just infinity putting 170~ms difference on first byte without js,css or other things.

I will try with bp now, can write results in 15mins

unsalkorkmaz commented 12 years ago

Multisite WP + BuddyPress. Default bp theme:

Total Load Time:    0.4643seconds avg.
Site Load Time  0.2449seconds avg.
Profile Overhead:   0.2194seconds avg.
Plugin Load Time:   0.1573seconds avg.
Theme Load Time:    0.0000seconds avg.
Core Load Time:     0.0814seconds avg.
Margin of Error:    0.0062seconds avg.
(0.4643 observed, 0.4581 expected)
Visits:     8
Number of PHP ticks:    5,892 calls avg.
Memory Usage:   26.91 MB avg.
MySQL Queries:  56 queries avg.

Pingdom: http://tools.pingdom.com/fpt/#!/e7NMDCunB/korkmaz.biz 84ms html

Webpagetest.org: http://www.webpagetest.org/result/120615_X2_Y31/ 230ms First Byte.

Multisite WP + BuddyPress. Infinity buddypress theme:

PressCrew-infinity-buddypress-1.0b3-22-gf75b24d.zip

I couldnt run P3 test because infinity gives error in admin page. It seems there is problem if u activate infinity on normal install, then convert that install to multisite and activate infinity again. Got this error with debug TRUE:

Fatal error: Uncaught exception 'Exception' with message 'Unable to get component "infinity-bp-custom-mysteryman_image": not registered' in /home/korkmaz/public_html/wp-content/themes/infinity/engine/ICE/base/registry.php:197
Stack trace:
#0 /home/korkmaz/public_html/wp-content/themes/infinity/engine/ICE/base/component.php(868): ICE_Registry->get('infinity-bp-cus...')
#1 /home/korkmaz/public_html/wp-content/themes/infinity/engine/ICE/ext/features/bp/custom-mysteryman/class.php(82): ICE_Component->get_suboption('image')
#2 [internal function]: ICE_Ext_Feature_Bp_Custom_Mysteryman->custom_mysteryman('http://korkmaz....', 64)
#3 /home/korkmaz/public_html/wp-includes/plugin.php(170): call_user_func_array(Array, Array)
#4 /home/korkmaz/public_html/wp-content/plugins/buddypress/bp-core/bp-core-avatars.php(269): apply_filters('bp_core_mystery...', 'http://korkmaz....', 64)
#5 /home/korkmaz/public_html/wp-content/plugins/buddypress/bp-core/bp-core-avatars.php(598): bp_core_fetch_avatar(Array)
#6 [internal function]: bp_core_fetch in /home/korkmaz/public_html/wp-content/themes/infinity/engine/ICE/base/registry.php on line 197

But frontend is working.

Pingdom test: http://tools.pingdom.com/fpt/#!/JkrOEWqiX/korkmaz.biz 276ms html Webpagetest.org: http://www.webpagetest.org/result/120615_2S_YH7/ 466 ms First Byte.

Btw i can give admin user/password for you to see error if u want.

MrMaz commented 12 years ago

I'm going to need a zip of your entire theme stack. Include the infinity/ you are using plus all of the child themes.

MrMaz commented 12 years ago

Regarding the error you are seeing I fixed that earlier today because I ran in to the same thing. The bleeding edge is not very stable right now.

unsalkorkmaz commented 12 years ago

I zipped themes folder: http://korkmaz.biz/wp-content/themes.tgz

Btw real production site is http://gapvitrin.com/ I have 986ms on first page html atm and its just too much tbh. 933ms is just "waiting" :-/ (PS: yeah color and icons are client's choise.lol) even you can see in footer: <!-- Generated in 0,883 seconds. (90 q) -->

MrMaz commented 12 years ago

I'll take a look tomorrow. It doesn't make much sense because I can get much faster than that even with dev mode ON with a heavy plugin install on a crappy dev box. Hopefully there is just something weird with the theme(s).

MrMaz commented 12 years ago

First off, I want everyone to know that we are taking Infinity performance very seriously. It is extremely important to us that Infinity run as fast as possible in line with how much functionality it provides. Bowe and I had a very long discussion which was triggered by this ticket to make sure we handle this kind of issue properly and professionally, now and in the future.

Our discussion resulted in several important decisions about Infinity and the priority of performance.

All of these being said, the feedback is extremely important to us. We DO want lots of feedback about Infinity's performance, but we would rather this kind of this issue be raised on the community forums instead of GitHub. GitHub is a tool we use to manage the code base and code issues like specific bugs and enhancements.

Looking back at how this ticket started I believe it doesn't fall under a bug or enhancement, but more like a complaint. It is probably a valid complaint, but we don't want our GitHub repos to turn into a place to file complaints because there is way to much personal preference and opinion involved in a complaint.

So I am going to close this ticket, and I hope that you will re-start this discussion on the community forums so we can get input and feedback from the community on what is a reasonable expectation for Infinity performance so we can begin working towards that goal.

MrMaz commented 12 years ago

Here is an article from CloudFlare which debunks some of the myths about first byte.

http://blog.cloudflare.com/ttfb-time-to-first-byte-considered-meaningles

Personally I think the only stat which matters is total download time. A browser can't even begin rendering the page until the entire document has been delivered, so I think first byte is pointless.

unsalkorkmaz commented 12 years ago

i had some xdebug profiles.. zip file: http://unsalkorkmaz.com/problems/infinity-xdebug.zip

You can inspect those with: http://sourceforge.net/projects/wincachegrind/

I believe lots of ICE_Files::theme_file_to_url calls because of overlay-images is one of problem. That function checks realpath every time.. Probably there is more points to check.

Basically my server is dedicated server with 8 cores so wait time is not high but in my local computer, i am waiting 6sec for home page first byte.

MrMaz commented 12 years ago

I use wincachegrind already so this is good. I checked your grind file and it looks very close to my results, except there seems to be a lot more calls to ->directive(). Is that a profile of RC1? My profile results of RC1 are 3x less execution time than beta3.

I don't think its realpath() because that has 499 calls totaling 58ms which is not great but only 5% of the theme_file_to_url() time. I am going to do more profiling on the 1.1 branch... if you want to optimize any code and submit a patch that would be great.

Don't forget about profiler overhead. I turn xdebug completely off when I don't need it because it slows my dev box down to a crawl.

unsalkorkmaz commented 12 years ago

I am not expert like you :-/ Just trying to read and understand whats happening (i didn't go any school related to php etc.. was student in engineering of electronics. lol)

just my opinions:

i think get_theme_root, get_theme_root_uri calls are not necessary in infinity/engine/ICE/utils/files.php . why dont you use WP_CONTENT_DIR and WP_CONTENT_URL ?

i see there is some type of file cache system.. but where is those caching stores? if you using apc for it, apc have big problems with mod_fcgid https://bugs.php.net/bug.php?id=57825 http://stackoverflow.com/questions/598444/how-to-share-apc-cache-between-several-php-processes-when-running-under-fastcgi I am using http://www.virtualmin.com/ for hosting management and expecting a different solution that supports apc in future (nginx,php-fpm etc). So i cant use apc for a while.

MrMaz commented 12 years ago

I try not to use the WP constants because in so many places they are used the return value is filtered. get_theme_root() passes the result through the 'theme_root' filter, for instance.

Right now the file path cache is only a per-request cache. It will turn into a real cache eventually, or be superseded by a better overall solution. We are not sure if our caching will be several extension which support the different cache plugins, or if we will do it internally.

MrMaz commented 12 years ago

Here is an article I found regarding XDebug profiling after I became suspicious that its time metrics where faulty.

http://stackoverflow.com/questions/7597690/can-xdebug-track-separately-the-time-spent-for-profiler-calls

Its a real eye opener. Basically XDebug does not exclude its own overhead from the time metrics, so for tuning code based on execution time, its useless. I can't believe it took me this long to figure this out. I think there are a ton of devs out there who are assuming that XDebug is excluding its overhead. I was.

I set up XHProf and the results are completely different.

MrMaz commented 12 years ago

The bleeding edge has some pretty significant performance improvements. We are starting on the 2.0 branch soon and the components loader is going to be overhauled to use lazy loading which should be a drastic boost to performance.