This forum is in READ-ONLY mode.
You can look around, but if you want to ask a new question, please use the new forum.
Home » legacy support » symfony 1.2 » Troubleshooting view loading extremely slowly.
Troubleshooting view loading extremely slowly. [message #97502] Fri, 16 April 2010 16:33 Go to next message
erisds  is currently offline erisds
Messages: 7
Registered: April 2010
Junior Member
Hi,

I am working on a large Symfony 1.2 application which has suddenly, inexplicably started to load very, very slowly for certain views in certain modules.

I am trying to troubleshoot/debug one of the frontend modules - "resultstable", the indexSuccess.php is loading v. slow. It does contain multiple, quite extensive queries, but this doesn't seem to be the cause. From when I first built the module & view and it loaded in ~4 seconds (not bad considering the queries). It now takes anything from 20seconds to 2minutes.

The problem is worst on the index.php controller & is not as bad on the dev controller (which seems odd). The index action/view has caching turned off, as although the page loads quickly when caching is on, this seems to be just hiding the issue.

I have turned logging on for the frontend production controller, and the log clearly shows where the time goes:

Apr 16 14:56:38 symfony [info] {sfViewCacheManager} Cache for " @sf_cache_partial?module=resultstable&action=_list_th_ta bular&sf_cache_key=0ad0c7db2785e069bcc3b51950782727 " does not exist
Apr 16 14:56:38 symfony [info] {sfPartialView} Render " /var/www/####/httpdocs/apps/front/modules/resultstable/templ ates/_list_th_tabular.php "
Apr 16 14:56:38 symfony [info] {sfViewCacheManager} Save cache for " @sf_cache_partial?module=resultstable&action=_list_th_ta bular&sf_cache_key=0ad0c7db2785e069bcc3b51950782727 "
Apr 16 14:58:06 symfony [info] {sfPHPView} Decorate content with "/var/www/####/httpdocs/apps/front/templates/layout.php"
Apr 16 14:58:06 symfony [info] {sfPHPView} Render "/var/www/####/httpdocs/apps/front/templates/layout.php"
Apr 16 14:58:06 symfony [info] {main} Call "element->executeHeader()"

You can see that Symfony is processing some caching & then stops for around 90 seconds. Here's another log with the caching turned off completely for the frontend application:

Apr 16 15:25:35 symfony [info] {sfPartialView} Render " /var/www/####/httpdocs/apps/front/modules/resultstable/templ ates/_filters.php "
Apr 16 15:25:36 symfony [info] {sfPartialView} Render " /var/www/####/httpdocs/apps/front/modules/resultstable/templ ates/_list_th_tabular.php "
Apr 16 15:27:12 symfony [info] {sfPHPView} Decorate content with "/var/www/####/httpdocs/apps/front/templates/layout.php"
Apr 16 15:27:12 symfony [info] {sfPHPView} Render "/var/www/####/httpdocs/apps/front/templates/layout.php"

Why would the decorator need so much time?

As I said, this has suddenly started to occur and I am not aware of having made changes which would cause this (no major changes to queries or templates). I have tried rolling back to a version when I know the code was executing in a reasonable time and even that doesn't seem to fix it.

Any help or just pointers of where to look for a solution would be much appreciated.

Thanks,

Eris

[Updated on: Fri, 16 April 2010 16:38]

Re: Troubleshooting view loading extremely slowly. [message #97610 is a reply to message #97502 ] Mon, 19 April 2010 12:36 Go to previous messageGo to next message
erisds  is currently offline erisds
Messages: 7
Registered: April 2010
Junior Member
This is infuriating because under the dev controller this takes just a second.

Apr 19 11:35:06 symfony [info] {sfPartialView} Render " /var/www/####/httpdocs/apps/front/modules/resultstable/templ ates/_list_th_tabular.php "
Apr 19 11:35:07 symfony [info] {sfPHPView} Decorate content with "/var/www/####/httpdocs/apps/front/templates/layout.php"
Apr 19 11:35:07 symfony [info] {sfPHPView} Render "/var/www/####/httpdocs/apps/front/templates/layout.php"

What could possibly cause this to take 1sec under dev, and 90secs under front?

It seems what is doing it is generating a set of URLs using link_to (some 600 of them). It's a lot of work but the dev controller doesn't even sniff at it Sad

[Updated on: Mon, 19 April 2010 12:44]

Re: Troubleshooting view loading extremely slowly. [message #97612 is a reply to message #97502 ] Mon, 19 April 2010 12:43 Go to previous messageGo to next message
halfer  is currently offline halfer
Messages: 9535
Registered: January 2006
Location: West Midlands, UK
Faithful Member
If you copy your prod database over to your dev database, are the response times still different?

Also, where you are getting "Cache ... does not exist" messages, is this due to correct expiry, or do you see a problem here? If you are expecting a cache hit where there is none, it might be a permissions problem inside your cache folder, and some cache file(s) are unreadable to the web server.


Remember Palestine
Re: Troubleshooting view loading extremely slowly. [message #97613 is a reply to message #97502 ] Mon, 19 April 2010 12:46 Go to previous messageGo to next message
erisds  is currently offline erisds
Messages: 7
Registered: April 2010
Junior Member
The prod and dev databases are exactly the same.

However I have several instances of the site running on different servers with vastly different databases. It happens on every server.

I don't think the cache is the problem as I have turned it off completely. Am no longer seeing those error messages but the prod controller continues to spend 90seconds decorating where the dev controller spends 1 second.

As I added above, if I comment out a line which uses link_to, the problem goes away.

However if the dev controller is not struggling then Symfony is obviously capable of handling what I want it to do... it just won't do it using the prod controller ?
Re: Troubleshooting view loading extremely slowly. [message #97616 is a reply to message #97502 ] Mon, 19 April 2010 13:02 Go to previous messageGo to next message
halfer  is currently offline halfer
Messages: 9535
Registered: January 2006
Location: West Midlands, UK
Faithful Member
Hmm, if everything is fine with caching turned off completely, could be a PHP problem? What MPM process are you using (FastCGI/Apache Handler etc)? What version of PHP?


Remember Palestine
Re: Troubleshooting view loading extremely slowly. [message #97618 is a reply to message #97502 ] Mon, 19 April 2010 13:08 Go to previous messageGo to next message
erisds  is currently offline erisds
Messages: 7
Registered: April 2010
Junior Member
PHP version 5.2.4

and I believe the Apache Handler

I just can't get my head around why the dev controller works. I guess I don't have a good enough understanding of the differences between prod & dev Sad
Re: Troubleshooting view loading extremely slowly. [message #97622 is a reply to message #97618 ] Mon, 19 April 2010 14:14 Go to previous messageGo to next message
old_sound  is currently offline old_sound
Messages: 21
Registered: November 2007
Junior Member
Eris,

While is hard to diagnose this from the distance, first I will recommend that you use something like XHProf, to find exactly which function is giving you problems.

You could do something like this http://gist.github.com/300261 to enable it, and then follow the instructions on the docs to interpret the results.

If you can't do something like that, I would take a look to the cache folder inside the routing cache. Maybe you have way to many routes there, which is a problem with the symfony routing system. I mention this because you talk about calls to link_to(). If you have thousands of routes, this means that the disk will have a hard work scanning the folder where the cache resides. At some point we had 300.000+ routes there, which made us switch to APC caching for the routing.

if you can get some XHProf runs out of your site, I could lend you a hand to interpret them, since I have all set up in my machine to do so.

Hope this helps,

Alvaro
Re: Troubleshooting view loading extremely slowly. [message #97696 is a reply to message #97502 ] Tue, 20 April 2010 18:34 Go to previous messageGo to next message
Japh  is currently offline Japh
Messages: 6
Registered: April 2010
Location: United Kingdom
Junior Member
Hi,

I'm working with Eris on this problem, so here's an update on what we've discovered so far, in the hopes you guy might have some more suggestions for us!

Using WebGrind, we've got a rough profile of what's happening here:
index.php/fa/1503/0/

I have tried switching routing to use memcache instead of file caching, and I have tried reducing the number of routes in the YAML file to only those required for this page (11 in total).

Still no luck. As you can see, it's taking over 35 seconds to load the page, and most of the time seems to be spent running "serialize" over the params to generate and MD5 string for the routing cache.

What it's actually drawing is basically a 33 row, 8 column table of scores with links to a details page. It seems to be this part of the page that takes 30 of the 35 seconds.

Any clues on what we can do to reduce this?

(If I've got any details slightly wrong, Eris, please correct me! Wink)

Re: Troubleshooting view loading extremely slowly. [message #97697 is a reply to message #97696 ] Tue, 20 April 2010 18:41 Go to previous messageGo to next message
erisds  is currently offline erisds
Messages: 7
Registered: April 2010
Junior Member
It's probably worth noting that we couldn't get XHProf running, which is why we took a look at webgrind/cachegrind instead.

We also have this system running on both a VM and a dedicated server with several different result sets.

The problem is the same across them all and the page load is just as slow for a 33 row table on one machine as it is for a 75 row table elsewhere.

It goes from running in ~10 seconds just outputting text in each cell, up to ~90 if we output a link in each. It's too slow in either case, but indicates that the problem is underlying in the routing system somewhere!
Re: Troubleshooting view loading extremely slowly. [message #97700 is a reply to message #97697 ] Tue, 20 April 2010 18:50 Go to previous messageGo to next message
old_sound  is currently offline old_sound
Messages: 21
Registered: November 2007
Junior Member
Try to play with this configuration values in the factories.yml file:

lazy_routes_deserialize: true
lookup_cache_dedicated_keys: true

They should be under the routing entry

They are quite tricky to get right, mostly depending on your project.

Regarding the route caching, I will recommend APC, since Memcached will require a TCP connection.

I would use Memcached for view caching for example, but not for the routing part.


Let me know if those settings work for you
Re: Troubleshooting view loading extremely slowly. [message #97702 is a reply to message #97502 ] Tue, 20 April 2010 19:43 Go to previous messageGo to next message
Japh  is currently offline Japh
Messages: 6
Registered: April 2010
Location: United Kingdom
Junior Member
Thank you for the suggestions! Unfortunately, they don't seem to have made a difference so far.

Here is the "routing" section from the factories.yml file:
 routing:
    class: sfPatternRouting
    param:
      lazy_routes_deserialize:          true
      lookup_cache_dedicated_keys:      true
      load_configuration:               true
      suffix:                           ''
      default_module:                   default
      default_action:                   index
      debug:                            %SF_DEBUG%
      logging:                          %SF_LOGGING_ENABLED%
      generate_shortest_url:            false
      extra_parameters_as_query_string: true
      cache:
        class: sfFileCache
        param:
          automatic_cleaning_factor: 0
          cache_dir:                 %SF_CONFIG_CACHE_DIR%/routing
          lifetime:                  31556926
          prefix:                    %SF_APP_DIR%/routing


Perhaps something's off there?
Re: Troubleshooting view loading extremely slowly. [message #97727 is a reply to message #97502 ] Wed, 21 April 2010 04:26 Go to previous messageGo to next message
old_sound  is currently offline old_sound
Messages: 21
Registered: November 2007
Junior Member
The only difference that I see is that we have this set to true:

generate_shortest_url: true

And that we use APC cache:

cache:
class: sfAPCCache
param:
automatic_cleaning_factor: 0
lifetime: 31556926

Re: Troubleshooting view loading extremely slowly. [message #97733 is a reply to message #97502 ] Wed, 21 April 2010 11:04 Go to previous messageGo to next message
halfer  is currently offline halfer
Messages: 9535
Registered: January 2006
Location: West Midlands, UK
Faithful Member
@erisds - I would tend to recommend an upgrade to a more recent version of PHP first, and then if that fails to make an impact, move from Apache Handler to FastCGI/fcgid.


Remember Palestine
Re: Troubleshooting view loading extremely slowly. [message #97734 is a reply to message #97502 ] Wed, 21 April 2010 11:06 Go to previous messageGo to next message
halfer  is currently offline halfer
Messages: 9535
Registered: January 2006
Location: West Midlands, UK
Faithful Member
@Japh - for clarity, can you confirm you are on 1.2.x too?

Can you both confirm that you're using the latest update to this branch?


Remember Palestine
Re: Troubleshooting view loading extremely slowly. [message #97739 is a reply to message #97502 ] Wed, 21 April 2010 11:22 Go to previous messageGo to next message
Japh  is currently offline Japh
Messages: 6
Registered: April 2010
Location: United Kingdom
Junior Member
@old_sound: I tried adding the parameter you mention, and also switching to APC caching, but no change at all.

The problem appears to mainly be with the CPU expense of PHP's serialize() function.

@halfer: We are using Symfony 1.2.5 (SVN external of this branch).

Before we go ahead and try different versions of PHP or switching to FastCGI, can you tell me your reasoning for the suggestions?

For example, "updating to PHP 5.2.13 has changes to X which may be related to serialize performance improvement".

Not looking forward to any potential fall-out from upgrading these things on development, staging, and production servers Sad

(Also, ErisDS and I are working on the same project, using identical VMs as development servers)
Re: Troubleshooting view loading extremely slowly. [message #97741 is a reply to message #97502 ] Wed, 21 April 2010 11:34 Go to previous messageGo to next message
old_sound  is currently offline old_sound
Messages: 21
Registered: November 2007
Junior Member
As Japh says, I don't see a reason to change the PHP version. PHP 5.3 can give you performance improvements, but not related to serialize.

@Japh

I'm pretty sure you did it, but I'll ask to confirm,

After changing the factories.yml you cleared the cache right?

And if you use APC and you have apc.stat = off in the php.ini or apc.ini config file, then you have to clear the APC file cache, to see the configuration changes.

Then, regarding the serialize() and those options I've told you, basically what symfony does is to cache in a big array all the routes, or to cache them individually. That's why probably it takes ages to serialize/deserialize them if you have too many routes.

I don't know what else to suggest
Re: Troubleshooting view loading extremely slowly. [message #97747 is a reply to message #97502 ] Wed, 21 April 2010 12:05 Go to previous messageGo to next message
halfer  is currently offline halfer
Messages: 9535
Registered: January 2006
Location: West Midlands, UK
Faithful Member
I don't have any concrete reasons for suggesting a PHP upgrade or MPM change. However in the case of a PHP change, I did mean to the latest in the 5.2 branch, rather than to 5.3, to minimise disruption.

My non-concrete reason is that you may be hitting a bug in the server stack, and I'd have thought on a spare machine it would be trivial to determine whether this makes a difference. Since it is quick to check, I'd have thought it was worth a try Smile


Remember Palestine
Re: Troubleshooting view loading extremely slowly. [message #97750 is a reply to message #97741 ] Wed, 21 April 2010 12:12 Go to previous messageGo to next message
Japh  is currently offline Japh
Messages: 6
Registered: April 2010
Location: United Kingdom
Junior Member
@old_sound: I certainly did clear the cache after making each change Smile

I have now upgraded from Symfony 1.2.5 to 1.2.12, and no change there really either (despite there being quite a few bug fixes in 1.2.7 especially relating to routing and serialization).

I will double-check the configuration settings you mention regarding APC, however the problem does appear more to be with serialization in preparation for cache creation... so not sure that will help.

If caching is turned on, there's generally not too much of a problem, until the cache expires and has to be regenerated. Taking 35+ seconds is a bit much for 11 routes.

Might have to work out exactly what's being serialized and if there's a way to reduce it...
Re: Troubleshooting view loading extremely slowly. [message #97789 is a reply to message #97502 ] Wed, 21 April 2010 17:20 Go to previous messageGo to next message
Japh  is currently offline Japh
Messages: 6
Registered: April 2010
Location: United Kingdom
Junior Member
Just to update anyone who's interested, after a number of hours of profiling and banging our heads on our desks, we realised that if we passed the explicit parameters for routing instead of entire objects then the serialize() function had considerably less to do.

By changing two functions to pass explicit parameters instead of whole objects, we reduced the page load time from ~40s to ~5s.

Make a note of that one!

Thanks for all your suggestions too Smile
Re: Troubleshooting view loading extremely slowly. [message #97790 is a reply to message #97502 ] Wed, 21 April 2010 17:27 Go to previous message
old_sound  is currently offline old_sound
Messages: 21
Registered: November 2007
Junior Member
Glad to hear that it got fixed, cool
Previous Topic:throw validator error schema on an embedded form
Next Topic:strange doctrine PDO error
Goto Forum:
  

powered by FUDforum - copyright ©2001-2004 FUD Forum Bulletin Board Software