High cpu load by mysql

After update from 4.4.2 to 4.4.5 a high cpu load produced by mysql is monitored. Also the shop is relativ slow. Debug output by entering the shop:

Execution time :5.0886
Memory usage: 9.557 MB (peak: 9.945 MB)
System memory usage: 10 MB (peak: 10 MB)
cl=start
----------------------------------------------------------
Profile start: 	5.09307s	100.09% 	1	*	5.09307s
Profile allarticles: 	4.85265s	95.36% 	1	*	4.85265s
Profile loadinglists: 	4.83793s	95.07% 	7	*	0.69113s
Profile oxNew: 	0.13412s	2.64% 	92	*	0.00146s
Profile getCategoryUri: 	0.0275s	0.54% 	31	*	0.00089s
Profile buildTree: 	0.02533s	0.5% 	1	*	0.02533s
Profile smarty_function_oxmultilang: 	0.01024s	0.2% 	54	*	0.00019s
Profile getDynamicUrl: 	0.00452s	0.09% 	3	*	0.00151s
Profile _getLangTranslationArray: 	0.00298s	0.06% 	65	*	5.0E-5s
Profile parseThroughSmarty: 	0.00216s	0.04% 	43	*	5.0E-5s
Profile _sortCats: 	0.00152s	0.03% 	1	*	0.00152s
Profile tagCloud: 	0.00143s	0.03% 	1	*	0.00143s
Profile oxAutoload: 	0.00105s	0.02% 	62	*	2.0E-5s
Profile oxviewconfig::getViewConfigParam: 	0.00029s	0.01% 	56	*	1.0E-5s
Profile isSearchEngine: 	5.0E-5s	0% 	2	*	3.0E-5s
Profile oxviewconfig::setViewConfigParam: 	5.0E-5s	0% 	13	*	0s

“Profile allarticles” holds very long time. What should be my next step to find out the reason for it? The shop contains 71000 articles.

best regards
Frank

Hi Frank,

can you check the mysql logs for long queries etc…
Also, please check the database collation of both versions and the scheme itself.

Regards

Hi Marco,

the database collation and the scheme are not different compared with the backup.

Here are the slow query logs after restarting mysqld:


Time                 Id Command    Argument
# Time: 110104  8:45:33
# User@Host: oxid1[oxid1] @ localhost []
# Query_time: 2  Lock_time: 0  Rows_sent: 0  Rows_examined: 137810
use oxid1;
select oxarticles.oxid from oxactions2article
                              left join oxarticles on oxarticles.oxid = oxactions2article.oxartid
                              left join oxactions on oxactions.oxid = oxactions2article.oxactionid
                              where oxactions2article.oxshopid = 'oxbaseshop' and oxactions2article.oxactionid = 'oxcatoffer' and (   oxactions.oxactive = 1  or  ( oxactions.oxactivefrom < '2011-01-04 08:45:31' and oxactions.oxactiveto > '2011-01-04 08:45:31' ) ) 
                              and oxarticles.oxid is not null and (  oxarticles.oxactive = 1   and ( oxarticles.oxstockflag != 2 or ( oxarticles.oxstock + oxarticles.oxvarstock ) > 0  )  and IF( oxarticles.oxvarcount = 0, 1, ( select 1 from oxarticles as art where art.oxparentid=oxarticles.oxid and ( art.oxactive = 1  ) and ( art.oxstockflag != 2 or art.oxstock > 0 ) limit 1 ) )  ) 
                              order by oxactions2article.oxsort;
# Time: 110104  8:48:46
# User@Host: oxid1[oxid1] @ localhost []
# Query_time: 158  Lock_time: 0  Rows_sent: 331  Rows_examined: 23171276
select oxartextends.oxid from oxartextends inner join oxarticles on oxarticles.oxid = oxartextends.oxid where oxarticles.oxissearch = 1 and match ( oxartextends.oxtags ) against( 'vorne/7075/4mm/trophy' IN BOOLEAN MODE ) and (  oxarticles.oxactive = 1   and ( oxarticles.oxstockflag != 2 or ( oxarticles.oxstock + oxarticles.oxvarstock ) > 0  )  and IF( oxarticles.oxvarcount = 0, 1, ( select 1 from oxarticles as art where art.oxparentid=oxarticles.oxid and ( art.oxactive = 1  ) and ( art.oxstockflag != 2 or art.oxstock > 0 ) limit 1 ) )  );
# Time: 110104  8:51:31
# User@Host: oxid1[oxid1] @ localhost []
# Query_time: 153  Lock_time: 0  Rows_sent: 331  Rows_examined: 23171276
select oxartextends.oxid from oxartextends inner join oxarticles on oxarticles.oxid = oxartextends.oxid where oxarticles.oxissearch = 1 and match ( oxartextends.oxtags ) against( 'hinten/aussen/trophy' IN BOOLEAN MODE ) and (  oxarticles.oxactive = 1   and ( oxarticles.oxstockflag != 2 or ( oxarticles.oxstock + oxarticles.oxvarstock ) > 0  )  and IF( oxarticles.oxvarcount = 0, 1, ( select 1 from oxarticles as art where art.oxparentid=oxarticles.oxid and ( art.oxactive = 1  ) and ( art.oxstockflag != 2 or art.oxstock > 0 ) limit 1 ) )  );
# Time: 110104  8:56:59
# User@Host: oxid1[oxid1] @ localhost []
# Query_time: 152  Lock_time: 0  Rows_sent: 326  Rows_examined: 22822311
select oxartextends.oxid from oxartextends inner join oxarticles on oxarticles.oxid = oxartextends.oxid where oxarticles.oxissearch = 1 and match ( oxartextends.oxtags ) against( 'hinten/7075/trophy' IN BOOLEAN MODE ) and (  oxarticles.oxactive = 1   and ( oxarticles.oxstockflag != 2 or ( oxarticles.oxstock + oxarticles.oxvarstock ) > 0  )  and IF( oxarticles.oxvarcount = 0, 1, ( select 1 from oxarticles as art where art.oxparentid=oxarticles.oxid and ( art.oxactive = 1  ) and ( art.oxstockflag != 2 or art.oxstock > 0 ) limit 1 ) )  );
# Time: 110104  9:06:58
# User@Host: oxid1[oxid1] @ localhost []
# Query_time: 119  Lock_time: 0  Rows_sent: 0  Rows_examined: 137808
select oxarticles.oxid, oxarticles.oxparentid, oxarticles.oxvarstock, oxarticles.oxvarcount, oxarticles.oxstock, oxarticles.oxstockflag, oxarticles.oxprice, oxarticles.oxvat, oxarticles.oxskipdiscounts, oxarticles.oxunitquantity, oxarticles.oxunitname, oxarticles.oxshopid, oxarticles.oxtitle, oxarticles.oxartnum, oxarticles.oxthumb, oxarticles.oxpicsgenerated, oxarticles.oxpic1, oxarticles.oxvarselect, oxarticles.oxtprice from oxartextends inner join oxarticles on oxarticles.oxid = oxartextends.oxid where match ( oxartextends.oxtags ) against( '\"hinten/7075/4mm/trophy\"' IN BOOLEAN MODE ) and (  oxarticles.oxactive = 1   and ( oxarticles.oxstockflag != 2 or ( oxarticles.oxstock + oxarticles.oxvarstock ) > 0  )  and IF( oxarticles.oxvarcount = 0, 1, ( select 1 from oxarticles as art where art.oxparentid=oxarticles.oxid and ( art.oxactive = 1  ) and ( art.oxstockflag != 2 or art.oxstock > 0 ) limit 1 ) )  )  LIMIT 70, 10;
# Time: 110104  9:09:29
# User@Host: oxid1[oxid1] @ localhost []
# Query_time: 151  Lock_time: 0  Rows_sent: 1  Rows_examined: 22822311
select count(*) from oxartextends inner join oxarticles
               on oxarticles.oxid = oxartextends.oxid where (  oxarticles.oxactive = 1   and ( oxarticles.oxstockflag != 2 or ( oxarticles.oxstock + oxarticles.oxvarstock ) > 0  )  and IF( oxarticles.oxvarcount = 0, 1, ( select 1 from oxarticles as art where art.oxparentid=oxarticles.oxid and ( art.oxactive = 1  ) and ( art.oxstockflag != 2 or art.oxstock > 0 ) limit 1 ) )  ) 
               and oxarticles.oxissearch = 1
               and match(oxartextends.oxtags)
               against ( 'hinten/7075/4mm/trophy' IN BOOLEAN MODE );
# Time: 110104  9:30:51
# User@Host: oxid1[oxid1] @ localhost []
# Query_time: 150  Lock_time: 0  Rows_sent: 326  Rows_examined: 22822311
select oxartextends.oxid from oxartextends inner join oxarticles on oxarticles.oxid = oxartextends.oxid where oxarticles.oxissearch = 1 and match ( oxartextends.oxtags ) against( 'hinten/7075/4mm/trophy' IN BOOLEAN MODE ) and (  oxarticles.oxactive = 1   and ( oxarticles.oxstockflag != 2 or ( oxarticles.oxstock + oxarticles.oxvarstock ) > 0  )  and IF( oxarticles.oxvarcount = 0, 1, ( select 1 from oxarticles as art where art.oxparentid=oxarticles.oxid and ( art.oxactive = 1  ) and ( art.oxstockflag != 2 or art.oxstock > 0 ) limit 1 ) )  );
# Time: 110104  9:41:12
# User@Host: oxid1[oxid1] @ localhost []
# Query_time: 118  Lock_time: 0  Rows_sent: 0  Rows_examined: 137808
select oxarticles.oxid, oxarticles.oxparentid, oxarticles.oxvarstock, oxarticles.oxvarcount, oxarticles.oxstock, oxarticles.oxstockflag, oxarticles.oxprice, oxarticles.oxvat, oxarticles.oxskipdiscounts, oxarticles.oxunitquantity, oxarticles.oxunitname, oxarticles.oxshopid, oxarticles.oxtitle, oxarticles.oxartnum, oxarticles.oxthumb, oxarticles.oxpicsgenerated, oxarticles.oxpic1, oxarticles.oxvarselect, oxarticles.oxtprice from oxartextends inner join oxarticles on oxarticles.oxid = oxartextends.oxid where match ( oxartextends.oxtags ) against( '\"hinten/aussen/trophy\"' IN BOOLEAN MODE ) and (  oxarticles.oxactive = 1   and ( oxarticles.oxstockflag != 2 or ( oxarticles.oxstock + oxarticles.oxvarstock ) > 0  )  and IF( oxarticles.oxvarcount = 0, 1, ( select 1 from oxarticles as art where art.oxparentid=oxarticles.oxid and ( art.oxactive = 1  ) and ( art.oxstockflag != 2 or art.oxstock > 0 ) limit 1 ) )  )  LIMIT 130, 10;


salut,

maybe its a problem with the cardinality. Look in oxarticles and oxcategories.

[QUOTE=gaertner_markus;47635]salut,

maybe its a problem with the cardinality. Look in oxarticles and oxcategories.[/QUOTE]

Hi, What exactly should I looking for in this tables?

Hi,

sorry, it took a while. Can you please run this commands in a terminal on your server (pls no phpMyAdmin!) and post the results:

select count(*) from oxartextends; 
select count(*) from oxarticles; 
select count(*) from oxactions; 
select count(*) from oxactions2article;

Regards

[QUOTE=Marco Steinhaeuser;49954]

Can you please run this commands in a terminal on your server (pls no phpMyAdmin!) and post the results:


mysql> select count(*) from oxartextends;
+----------+
| count(*) |
+----------+
|    69794 | 
+----------+
1 row in set (0.02 sec)

mysql> select count(*) from oxarticles;
+----------+
| count(*) |
+----------+
|    69795 | 
+----------+
1 row in set (0.02 sec)

mysql> select count(*) from oxactions;
+----------+
| count(*) |
+----------+
|       11 | 
+----------+
1 row in set (0.00 sec)

mysql> select count(*) from oxactions2article;
+----------+
| count(*) |
+----------+
|       22 | 
+----------+
1 row in set (0.00 sec)


[/QUOTE]

Since yesterday I’m using 4.4.6_32697

Thanks for helping,
Frank

Hi Frank,

sorry, cannot determine any strange behaviour. You just have 70k product items in your store - no disproportional amount of variants or something … I am just wondering wher this figure (22822311) comes from…

BTW: Do you have the same behaviour on your staging machine (in a different server environemnt)?

Regards

[QUOTE=Marco Steinhaeuser;50026]Hi Frank,
I am just wondering wher this figure (22822311) comes from…
[/QUOTE]

At mysql console, the query

SELECT oxartextends.oxid FROM oxartextends INNER JOIN oxarticles ON oxarticles.oxid = oxartextends.oxid WHERE oxarticles.oxissearch =1AND MATCH (
oxartextends.oxtags) AGAINST ('hinten/7075/trophy' IN BOOLEAN MODE)
AND (oxarticles.oxactive =1 AND (oxarticles.oxstockflag !=2OR (oxarticles.oxstock + oxarticles.oxvarstock) >0) AND IF( oxarticles.oxvarcount =0, 1, (SELECT 1 FROM oxarticles AS art WHERE art.oxparentid = oxarticles.oxid AND (art.oxactive =1
) AND (art.oxstockflag !=2 OR art.oxstock >0) LIMIT 1 )));

has 324 results and takes a time of 148.4855 sek.

[QUOTE=Marco Steinhaeuser;50026]
BTW: Do you have the same behaviour on your staging machine (in a different server environemnt)?
[/QUOTE]
Sorry, what do you mean exactly?

best regards
Frank

[QUOTE=digidax;50035]Sorry, what do you mean exactly?[/QUOTE]

Have you tried it on a different server?

Regards

[QUOTE=Marco Steinhaeuser;50041]Have you tried it on a different server?

Regards[/QUOTE]

I have moved online (hot migration) this virtual container to an other hardware node and now no slow queries are logged. Now the shop is also delivered out much more faster the pages.

My next job is to find out the reason for this fasten handbrake at the old hardware node.

Thank you for your support.

best regards
Frank

Hi Frank,

would be interesting to know the reason. Please feel free to share it in this thread if you can locate it.

Regards

The problem was solved by recompiling the kernel of one of our cluster node. Now both nodes have identical performance.

best regards
Frank