Just updated to 4.8.0 using automatic updates script and the whole system became really slow. It takes nearly to minutes for the admin interface to load.
Acquiring locks is also quite slow, but is quicker after releasing and then acquiring locks for the same asset.
Anyone else experienced this?
Thanks,
Anton.
edit: actually the whole system is really slow. Sites take a while to load as well. Anything outside matrix seems to be absolutely fine.
Restored from back up and tried updating from 4.4.2 to 4.6.0. Everything went great. Updated from 4.6.0 to 4.6.2 and everything is dead slow now.
OK, the issue kick is after the update to 4.6.1.
The only difference I can see in the 4.6.0 to 4.6.1 def is this:
<run_script id="move_squid_config_to_external_tools" comment="Move squid caching config from Preferences to External Tools Config.">
<command>./scripts/upgrade/upgrade_clear_squid_cache_preferences.php</command>
<args>
<arg>pwd</arg>
</args>
</run_script>
There are just minor changes between 4.6.0 to 4.6.1 and i can't find any change is core and suspicious.
http://matrix.squizsuite.net/patches/4.6.1
The "Move squid caching config from Preferences to External Tools Config." step is a special step that allows squid caching configuration to be stored in tools.inc rather than treated as preference in preference.inc. It shouldn't really matter to admin interface.
Can you remove that step in the auto upgrade xml file and test again the upgrade from 4.6.0 to 4.6.1 to see if it's getting slow? You can run the script manually afterwards (otherwise you will get errors in squid cache tools interface).
Is it only slow in loading admin interface? how about frontend? Any errors in log? Is there a testing system for us to investigate? you can email me.
I will setup a 4.6.0 to 4.6.1 upgrade locally and try to replicate it.
[quote]
There are just minor changes between 4.6.0 to 4.6.1 and i can't find any change is core and suspicious.
http://matrix.squizsuite.net/patches/4.6.1
The "Move squid caching config from Preferences to External Tools Config." step is a special step that allows squid caching configuration to be stored in tools.inc rather than treated as preference in preference.inc. It shouldn't really matter to admin interface.
Can you remove that step in the auto upgrade xml file and test again the upgrade from 4.6.0 to 4.6.1 to see if it's getting slow? You can run the script manually afterwards (otherwise you will get errors in squid cache tools interface).
Is it only slow in loading admin interface? how about frontend? Any errors in log? Is there a testing system for us to investigate? you can email me.
I will setup a 4.6.0 to 4.6.1 upgrade locally and try to replicate it.
[/quote]
Thank you Edison. Was trying to run the upgrade but keep getting the "failed checking out mysource matrix core" and "There was a problem checking out 4-6-0 from CVS to check for modifications." errors now.
[quote]
Thank you Edison. Was trying to run the upgrade but keep getting the "failed checking out mysource matrix core" and "There was a problem checking out 4-6-0 from CVS to check for modifications." errors now.
[/quote]
Have you modified the code in any way?
[quote]
Have you modified the code in any way?
[/quote]
Which code? Took out the following from the 4.6.0-4.6.1 def as Edison suggested:
<run_script id="move_squid_config_to_external_tools" comment="Move squid caching config from Preferences to External Tools Config.">
<command>./scripts/upgrade/upgrade_clear_squid_cache_preferences.php</command>
<args>
<arg>pwd</arg>
</args>
</run_script>
[quote]
Thank you Edison. Was trying to run the upgrade but keep getting the "failed checking out mysource matrix core" and "There was a problem checking out 4-6-0 from CVS to check for modifications." errors now.
[/quote]
Can you try again now? I rebooted the server this morning for server updates (though you posted last night, I don't think we had any problems then).
If you can't give us access. Can you email me an Xdebug Cachegrind profile for the slow loading of interface?
That will give us some ideas which functions / areas taking so much time.
my email is ewang@squiz.com.au
[quote]
If you can't give us access. Can you email me an Xdebug Cachegrind profile for the slow loading of interface?
That will give us some ideas which functions / areas taking so much time.
my email is ewang@squiz.com.au
[/quote]
Hi Edison,
The problem is that I can no longer upgrade. This is what I get:
Checking for differences between 4.6.0 and existing code [ Checking out MySource Matrix Core… ]Checking out MySource Matrix Core —
/home/websites/4.6.1/automatic_upgrades/tmp$ cvs -d ':pserver:anonymous@public-cvs.squiz.net:/home/public/core' co -d 'mysource_4-6-0' -r mysource_4-6-0 -P mysource_matrix 2> /dev/null
[ FAILED checking out MySource Matrix Core ]
cvs -d ':pserver:anonymous@public-cvs.squiz.net:/home/public/core' co -d 'mysource_4-6-0' -r mysource_4-6-0 -P mysource_matrix 2> /dev/null
There was a problem checking out 4-6-0 from CVS to check for modifications.
I will be able to give you access. Do you need the server access or matrix? But I would like to actually upgrade first myself, as I need to make a fresh backup beforehand.
Thank you for the help!
Hi Anton,
Try now - I've fixed the problem with this not working.
[quote]
Hi Edison,
The problem is that I can no longer upgrade. This is what I get:
Checking for differences between 4.6.0 and existing code [ Checking out MySource Matrix Core… ]Checking out MySource Matrix Core —
/home/websites/4.6.1/automatic_upgrades/tmp$ cvs -d ':pserver:anonymous@public-cvs.squiz.net:/home/public/core' co -d 'mysource_4-6-0' -r mysource_4-6-0 -P mysource_matrix 2> /dev/null
[ FAILED checking out MySource Matrix Core ]
cvs -d ':pserver:anonymous@public-cvs.squiz.net:/home/public/core' co -d 'mysource_4-6-0' -r mysource_4-6-0 -P mysource_matrix 2> /dev/null
There was a problem checking out 4-6-0 from CVS to check for modifications.
I will be able to give you access. Do you need the server access or matrix? But I would like to actually upgrade first myself, as I need to make a fresh backup beforehand.
Thank you for the help!
[/quote]
[quote]
Hi Anton,
Try now - I've fixed the problem with this not working.
[/quote]
Thank you Chris. I'll give it ago after my backup is done.
So, updated to 4.6.1 and it's dead slow again 
Update: 55 seconds before I get the top bar with the Squiz logo…
You will need developer to do some debugging on your server to figure out why.
If you are Squiz UK client, please contact Squiz UK Support to get their developer to look into this issue.
I had a look at your system's error log ( i have no write access, no Matrix backend access).
This error looks strange, your Matrix session directory should allow apache to write session to it. That's the closest error that might relate to slowness.
[2012-03-13 21:49:30][0:MySource System][2:php warning][R] (Unknown:0) - Unknown: Failed to write session data (files). Please verify that the current setting of session.save_path is correct (…/mysource_matrix/cache)
The problem is identified. It's because of system internal messages.
I reverted a bug fix on your system, so it's much faster again.
http://bugs.matrix.squiz.net/view_bug.php?bug_id=5455
The bug fix introduced a different way of querying internal message DB table, accidentally making it slow for large tables.
Your message table is huge:
matrix=> select count(*) from sq_internal_msg;
count
---------
4178290
(1 row)
That's why it was super slow for you.
I recommend using a maintenance script to remove old messages.
http://manuals.matrix.squizsuite.net/server-administrator/chapters/remove-internal-messages-script
I will need to file a bug report for this, and find a proper way to re-fix that bug report.
If you continue your upgrade, my local change will be overridden. But if you can just clean up your internal message table, I believe it won't give you any more performance issues.
Edison!, thank you SO much for all your help!
I will need to see why there are so many messages. There are quite a few users on the system, so I will need to investigate, where these messages are coming from.
Once again, THANK YOU!!!
Hi,
So, upgraded to 4.8.0, deleted internal messages via a script. The system is slow again…
After running the script to remove internal messages, I get the following from the database:
sq_internal_msg | 909
sq_internal_msg_to_and_type | 244
sq_internal_msg_type | 212
sq_internal_msg_userto | 114
Those are basically taking up 1.5gb.
"php remove_internal_message.php -s /home/websites/mysource_matrix/ -p 1h" just now returned: 272 INTERNAL MESSAGES DELETED.
[quote]
After running the script to remove internal messages, I get the following from the database:
sq_internal_msg | 909
sq_internal_msg_to_and_type | 244
sq_internal_msg_type | 212
sq_internal_msg_userto | 114
Those are basically taking up 1.5gb.
"php remove_internal_message.php -s /home/websites/mysource_matrix/ -p 1h" just now returned: 272 INTERNAL MESSAGES DELETED.
[/quote]
Since you cleaned up so much data, log in to psql, then:
vacuum full sq_internal_msg;
reindex table sq_internal_msg;
and see how it performs now. Those numbers should also drop considerably.
(autovacuum in postgresql should clean this up but such a large data change might need this help).
[quote]
Since you cleaned up so much data, log in to psql, then:
vacuum full sq_internal_msg;
reindex table sq_internal_msg;
and see how it performs now. Those numbers should also drop considerably.
(autovacuum in postgresql should clean this up but such a large data change might need this help).
[/quote]
Yes!!! Chris, thank you! It's down to 3.1GB now.
OK, just a couple of things to polish off, but then I don't know how serious these are:
Running php system_check.php --system=/home/websites/mysource_matrix/ --verbose I get the following (quite a few lines 
):
Invalid Links on Link Tree Test [ OK ]
General Status Check [ info ]
There are 8010 asset(s) on the system
There are 8133 asset link(s) on the system
Invalid Incomplete Attachments Test [ OK ]
Form Integrity Test [ OK ]
Orphaned Assets Test [ OK ]
Invalid Matrix Links Test [ OK ]
Invalid Number of Kids on Link Tree Test [ !! ]
There are 1 invalid number of kids found on the system
Link #7534 has 731 kids listed, but actually 548 kids were found
Dead Assets Test [ OK ]
Broken Sort Order Test [ !! ]
There are 28 broken sort orders found on the system
The Asset #424 has 2 assets underneath, but the sort order finishes at 0
The Asset #141 has 15 assets underneath, but the sort order finishes at 13
The Asset #4133 has 12 assets underneath, but the sort order finishes at 10
The Asset #9740 has 9 assets underneath, but the sort order finishes at 7
The Asset #4177 has 8 assets underneath, but the sort order finishes at 6
The Asset #2413 has 6 assets underneath, but the sort order finishes at 4
The Asset #2499 has 4 assets underneath, but the sort order finishes at 2
The Asset #43 has 11 assets underneath, but the sort order finishes at 7
The Asset #4240 has 7 assets underneath, but the sort order finishes at 5
The Asset #5625 has 8 assets underneath, but the sort order finishes at 6
The Asset #4281 has 23 assets underneath, but the sort order finishes at 21
The Asset #3239 has 34 assets underneath, but the sort order finishes at 32
The Asset #4328 has 8 assets underneath, but the sort order finishes at 6
The Asset #3594 has 268 assets underneath, but the sort order finishes at 266
The Asset #526 has 4 assets underneath, but the sort order finishes at 2
The Asset #12292 has 15 assets underneath, but the sort order finishes at 13
The Asset #9248 has 8 assets underneath, but the sort order finishes at 5
The Asset #12308 has 15 assets underneath, but the sort order finishes at 13
The Asset #63 has 29 assets underneath, but the sort order finishes at 25
The Asset #8851 has 1 assets underneath, but the sort order finishes at 1
The Asset #3375 has 14 assets underneath, but the sort order finishes at 12
The Asset #532 has 4 assets underneath, but the sort order finishes at 2
The Asset #5641 has 550 assets underneath, but the sort order finishes at 547
The Asset #193 has 14 assets underneath, but the sort order finishes at 12
The Asset #147 has 4 assets underneath, but the sort order finishes at 2
The Asset #393 has 7 assets underneath, but the sort order finishes at 5
The Asset #5493 has 24 assets underneath, but the sort order finishes at 22
The Asset #2629 has 7 assets underneath, but the sort order finishes at 5
Fragmented Rollback Test [ OK ]
Fragmented Attributes Test [ !! ]
There are 84 fragmented attribute(s) on the system
Asset #4097 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4097 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Asset #4096 on the attributes table does not exist
Attribute #3450 on the attributes table does not exist
Attribute #3450 on the attributes table does not exist
Attribute #3448 on the attributes table does not exist
Attribute #3448 on the attributes table does not exist
Attribute #3520 on the attributes table does not exist
Attribute #3520 on the attributes table does not exist
Attribute #3523 on the attributes table does not exist
Attribute #3523 on the attributes table does not exist
Attribute #3528 on the attributes table does not exist
Attribute #3528 on the attributes table does not exist
Attribute #3529 on the attributes table does not exist
Attribute #3529 on the attributes table does not exist
Attribute #3521 on the attributes table does not exist
Attribute #3521 on the attributes table does not exist
Attribute #3450 on the attributes table does not exist
Attribute #3448 on the attributes table does not exist
Attribute #3520 on the attributes table does not exist
Attribute #3523 on the attributes table does not exist
Attribute #3528 on the attributes table does not exist
Attribute #3529 on the attributes table does not exist
Attribute #3521 on the attributes table does not exist
Attribute #3450 on the attributes table does not exist
Attribute #3448 on the attributes table does not exist
Attribute #3520 on the attributes table does not exist
Attribute #3523 on the attributes table does not exist
Attribute #3528 on the attributes table does not exist
Attribute #3529 on the attributes table does not exist
Attribute #3521 on the attributes table does not exist
Attribute #3450 on the attributes table does not exist
Attribute #3448 on the attributes table does not exist
Attribute #3520 on the attributes table does not exist
Attribute #3523 on the attributes table does not exist
Attribute #3528 on the attributes table does not exist
Attribute #3529 on the attributes table does not exist
Attribute #3521 on the attributes table does not exist
Attribute #3450 on the attributes table does not exist
Attribute #3448 on the attributes table does not exist
Attribute #3520 on the attributes table does not exist
Attribute #3523 on the attributes table does not exist
Attribute #3528 on the attributes table does not exist
Attribute #3529 on the attributes table does not exist
Attribute #3521 on the attributes table does not exist
User Permissions Test [ OK ]
HTML Tidy Errors Test [ OK ]
Dead File Revisions [ OK ]
There are no orphaned file repository entries.
Submission Integrity Test [ OK ]
Not so much worried about the Broke sort order test, as the missing links are of type of notice or type_3 ("design::system::frontend", "css_cache", "thumbnail" etc..). I understand it make sense that these errors come up then.
I am slightly confused by the attribute errors. For example, 3520 is just a standard page, 3521 is the bodycopy. What could be causing these.
"Link #7534 has 731 kids listed, but actually 548 kids were found" is a little weird, as there are only 4 "kids".
AND now the last question. I ran php system_integrity_check_indexes.php /home/websites/mysource_matrix/ as well. This gave me the wollowing output:
Some tables have incorrect names for primary keys.
This won't cause any problems, but upgrade guides may be harder to follow
as they expect the names to be a certain way.
To fix these tables, run the following commands
They can take a while depending on the size of the table.
BEGIN;
ALTER TABLE ONLY sq_ast_attr_val DROP CONSTRAINT sq_ast_attr_val_pkey;
ALTER TABLE sq_ast_attr_val ADD CONSTRAINT ast_attr_val_pk PRIMARY KEY (assetid,attrid,contextid);
ALTER TABLE ONLY sq_rb_ast_attr_val DROP CONSTRAINT sq_rb_ast_attr_val_pkey;
ALTER TABLE sq_rb_ast_attr_val ADD CONSTRAINT rb_ast_attr_val_pk PRIMARY KEY (sq_eff_from,assetid,attrid,contextid);
ALTER TABLE ONLY sq_ast_attr_uniq_val DROP CONSTRAINT sq_ast_attr_uniq_val_pkey;
ALTER TABLE sq_ast_attr_uniq_val ADD CONSTRAINT ast_attr_uniq_val_pk PRIMARY KEY (owning_attrid,contextid,custom_val);
ALTER TABLE ONLY sq_rb_ast_attr_uniq_val DROP CONSTRAINT sq_rb_ast_attr_uniq_val_pkey;
ALTER TABLE sq_rb_ast_attr_uniq_val ADD CONSTRAINT rb_ast_attr_uniq_val_pk PRIMARY KEY (sq_eff_from,owning_attrid,contextid,custom_val);
ALTER TABLE ONLY sq_ast_mdata_val DROP CONSTRAINT sq_ast_mdata_val_pkey;
ALTER TABLE sq_ast_mdata_val ADD CONSTRAINT ast_mdata_val_pk PRIMARY KEY (assetid,fieldid,contextid);
ALTER TABLE ONLY sq_rb_ast_mdata_val DROP CONSTRAINT sq_rb_ast_mdata_val_pkey;
ALTER TABLE sq_rb_ast_mdata_val ADD CONSTRAINT rb_ast_mdata_val_pk PRIMARY KEY (sq_eff_from,assetid,fieldid,contextid);
ALTER TABLE ONLY sq_ast_mdata_dflt_val DROP CONSTRAINT sq_ast_mdata_dflt_val_pkey;
ALTER TABLE sq_ast_mdata_dflt_val ADD CONSTRAINT ast_mdata_dflt_val_pk PRIMARY KEY (assetid,contextid);
ALTER TABLE ONLY sq_rb_ast_mdata_dflt_val DROP CONSTRAINT sq_rb_ast_mdata_dflt_val_pkey;
ALTER TABLE sq_rb_ast_mdata_dflt_val ADD CONSTRAINT rb_ast_mdata_dflt_val_pk PRIMARY KEY (sq_eff_from,assetid,contextid);
ALTER TABLE ONLY sq_sch_idx DROP CONSTRAINT sq_sch_idx_pkey;
ALTER TABLE sq_sch_idx ADD CONSTRAINT sch_idx_pk PRIMARY KEY (value,assetid,component,contextid);
COMMIT;
------------------------------------
------------------------------------
Extra indexes have been found on the following tables.
If these changes have been made deliberately, ignore this warning.
This can lead to performance loss.
To remove these, run the following command(s):
These were found on table sq_ast_attr_val:
DROP INDEX sq_ast_attr_val_contextid;
These were found on table sq_internal_msg:
DROP INDEX sq_internal_msg_userto;
------------------------------------
Is this something I acutally missed during previous upgrades or should I ignore this?
Sorry about the amount of text, but i though it would be best to just output everything.
Thank you all!