"clientScript" Application component takes a long time to load after POST

boydlee · April 17, 2012, 8:44am

Hi,

So I’m fairly new to Yii, even though I built some sites years ago on Prado.

I have a current problem where on a POST, my page can take up to a minute to perform the “Loading clientScript application component” task. Originally I thought my database had some sort of issue, but after putting tracing on I can see that isn’t the case, and the clientScript (system.CModule) task is what is taking forever to complete. It’s strange because sometimes it works in milliseconds, sometimes a few seconds, and other times up to a minute.

Here’s a trace example:

[i]17:37:19.657463 profile system.db.CDbCommand.query

begin:system.db.CDbCommand.query(update users set role_id = 2, featured =

1, first_name = ‘Boydlee’, last_name = ‘Pollentine’, username = ‘boydlee’,

password = ‘blah’, user_photo =

‘http ://a0.twimg.com/profile_images/1743928419/efad18b1-bfd0-49a9-a1ef-271f402084ad_normal.png’,

twitter = ‘boydleep’, email_address = ‘boydlee@gmail.com’, show_user = 1

WHERE user_id = 41)

17:37:19.657874 profile system.db.CDbCommand.query

end:system.db.CDbCommand.query(update users set role_id = 2, featured = 1,

first_name = ‘Boydlee’, last_name = ‘Pollentine’, username = ‘boydlee’,

password = ‘blah’, user_photo =

‘http ://a0.twimg.com/profile_images/1743928419/efad18b1-bfd0-49a9-a1ef-271f402084ad_normal.png’,

twitter = ‘boydleep’, email_address = ‘boydlee@gmail.com’, show_user = 1

WHERE user_id = 41)

[b]

17:38:17.165842 trace system.CModule

Loading "clientScript" application component

in /var/www/protected/controllers/UsersController.php (458)

in /var/www/index.php (14)[/b][/i]

Does anyone have any idea? I am using the latest version of Yii, PHP 5.3, Apache 2 on Ubuntu 11 and MySQL 5. I also have APC turned on, am doing DB schema caching, etc. The page in question just performs an update on a user record and then reloads the page after the POST - that’s pretty much it.

Any help appreciated!

Thanks,

Boydlee

Haensel · April 17, 2012, 9:29am

EDIT: Deleted my bogus response because telling you nonsense

boydlee · April 17, 2012, 9:35am

Hi,

The password values shown here are just dummies, so it’s fine. I originally thought those timestamp values were also the start of the task, but you can see the query here only takes milliseconds (there’s a start and end timestamp for the query) and then from that to the execution of the clientscript bit takes nearly a minute. The database has only a couple of dozen rows in it, and the update that occurs is happening on the primary key, there is no reason for the query to be taking any more time than a few milliseconds as shown. I can execute sql scripts against the database directly all day long via PHPmyadmin or whatever, and it performs fine.

This is running on a scaled cloud server too - it’s the only site on there with over 1GB of RAM, there’s no way it could be running out of resource IMHO.

Haensel · April 17, 2012, 9:50am

Yes, i got that seconds after writing the response (see edited post above)

I assume you looked at your controller code for any additional logic that could cause that (loops etc.) because then the only thing that comes to my mind now is apache. Any chances of taking a look at the apache and php logs?

boydlee · April 17, 2012, 9:52am

boydlee:

Hi,

The password values shown here are just dummies, so it’s fine. I originally thought those timestamp values were also the start of the task, but you can see the query here only takes milliseconds (there’s a start and end timestamp for the query) and then from that to the execution of the clientscript bit takes nearly a minute. The database has only a couple of dozen rows in it, and the update that occurs is happening on the primary key, there is no reason for the query to be taking any more time than a few milliseconds as shown. I can execute sql scripts against the database directly all day long via PHPmyadmin or whatever, and it performs fine.

This is running on a scaled cloud server too - it’s the only site on there with over 1GB of RAM, there’s no way it could be running out of resource IMHO.

Will take your advice and have another look at the logs today (am on a train right now). I did look once before, didn’t notice anything unusual but who knows.

boydlee · April 18, 2012, 3:27pm

Unfortunately I have checked again and the logs are clean. Running out of ideas on this one

Haensel · April 18, 2012, 3:33pm

Maybe there really is a problem within your controller/view code. Do you mind posting it in here? If that’s not the reason I am also running out of ideas.

jmclem · April 18, 2012, 4:47pm

Hi,

maybe profiling could help here; this could tell you where the execution time was spent.

I saw there are possibilities within Yii (didn’t use it myself), which require that you insert profiling code, like


Yii::beginProfile('blockID');

...

Yii::endProfile('blockID');

.

You could also use xdebug profiling (does not require code modification), and interpret results graphically with kcachegrind. Have a first look here : xdebug.org/docs/profiler

HTH,

JM.

boydlee · April 19, 2012, 12:02pm

Jean-Marie:

Hi,

maybe profiling could help here; this could tell you where the execution time was spent.

I saw there are possibilities within Yii (didn’t use it myself), which require that you insert profiling code, like
Yii::beginProfile('blockID');

...

Yii::endProfile('blockID');
.

You could also use xdebug profiling (does not require code modification), and interpret results graphically with kcachegrind. Have a first look here : xdebug.org/docs/profiler

HTH,

JM.

Thanks for all your replies… I finally worked out that it was an encryption class I was using - for some reason it would often stall. It wasn’t my class, so I haven’t dug into how to fix it yet, but I have managed to work out the problem.