Slow queries log and search queries

[SecondSight]

Hello !

My mysql slow queries log file is full of lines like these ones :

Quote

# Query_time: 8.079695  Lock_time: 0.000034 Rows_sent: 1  Rows_examined: 18872
SET timestamp=1470944284;
/*IPS\Content\Search\_Results::count:536*/ SELECT COUNT(*) FROM `ibf_core_search_index` AS `main` WHERE ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) OR index_class='IPS\\forums\\Topic\\Post' OR ( index_class IN('IPS\\cms\\Records1','IPS\\cms\\Records\\Comment1','IPS\\cms\\Records\\Review1') ) OR ( index_class IN('IPS\\cms\\Records2','IPS\\cms\\Records\\Comment2','IPS\\cms\\Records\\Review2') ) OR ( index_class IN('IPS\\blog\\Entry','IPS\\blog\\Entry\\Comment') ) OR ( index_class IN('IPS\\gallery\\Image','IPS\\gallery\\Image\\Comment','IPS\\gallery\\Image\\Review') ) OR ( index_class IN('IPS\\downloads\\File','IPS\\downloads\\File\\Comment','IPS\\downloads\\File\\Review') ) OR ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review') ) OR index_class='IPS\\nexus\\Package\\Review' ) AND MATCH(index_content,index_title) AGAINST ('\"+ce1-ce2\"' IN BOOLEAN MODE) AND ( index_permissions = '*' OR ( FIND_IN_SET(3,index_permissions) OR FIND_IN_SET('m175804',index_permissions) ) ) AND index_hidden=0;

 

Quote

/*IPS\Content\Search\Mysql\_Query::search:308*/ SELECT main.* FROM `ibf_core_search_index` AS `main` WHERE ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) OR index_class='IPS\\forums\\Topic\\Post' OR ( index_class IN('IPS\\cms\\Records1','IPS\\cms\\Records\\Comment1','IPS\\cms\\Records\\Review1') ) OR ( index_class IN('IPS\\cms\\Records2','IPS\\cms\\Records\\Comment2','IPS\\cms\\Records\\Review2') ) OR ( index_class IN('IPS\\blog\\Entry','IPS\\blog\\Entry\\Comment') ) OR ( index_class IN('IPS\\gallery\\Image','IPS\\gallery\\Image\\Comment','IPS\\gallery\\Image\\Review') ) OR ( index_class IN('IPS\\downloads\\File','IPS\\downloads\\File\\Comment','IPS\\downloads\\File\\Review') ) OR ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review') ) OR index_class='IPS\\nexus\\Package\\Review' ) AND ( ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) AND index_is_last_comment=1 ) OR ( index_class='IPS\\forums\\Topic\\Post' AND index_is_last_comment=1 ) OR ( ( index_class IN('IPS\\cms\\Records1','IPS\\cms\\Records\\Comment1') ) AND index_is_last_comment=1 ) OR ( ( index_class IN('IPS\\cms\\Records2','IPS\\cms\\Records\\Comment2') ) AND index_is_last_comment=1 ) OR ( ( index_class IN('IPS\\blog\\Entry','IPS\\blog\\Entry\\Comment') ) AND index_is_last_comment=1 ) OR ( ( index_class IN('IPS\\gallery\\Image','IPS\\gallery\\Image\\Comment') ) AND index_is_last_comment=1 ) OR ( ( index_class IN('IPS\\downloads\\File','IPS\\downloads\\File\\Comment') ) AND index_is_last_comment=1 ) OR ( ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment') ) AND index_is_last_comment=1 ) ) AND ( ( ( index_class IN('IPS\\forums\\Topic','IPS\\forums\\Topic\\Post') ) AND (( index_container_id=4 AND index_date_updated > 1459323308) OR ( index_container_id=5 AND index_date_updated > 1459326210) OR ( index_container_id=15 AND index_date_updated > 1459323308) OR ( index_container_id=19 AND index_date_updated > 1459323308) OR ( index_container_id=21 AND index_date_updated > 1459324266) OR ( index_container_id=22 AND index_date_updated > 1460423032) OR ( index_container_id=28 AND index_date_updated > 1459323308) OR ( index_container_id=41 AND index_date_updated > 1459323308) OR ( index_container_id=129 AND index_date_updated > 1459323323) OR ( index_container_id=130 AND index_date_updated > 1459323308) OR ( index_container_id=135 AND index_date_updated > 1459323308) OR ( index_container_id=138 AND index_date_updated > 1459323308) OR ( index_container_id=139 AND index_date_updated > 1459323308) OR ( index_container_id=140 AND index_date_updated > 1459323308) OR ( index_container_id=144 AND index_date_updated > 1459323308) OR ( index_container_id=147 AND index_date_updated > 1459323308) OR ( index_container_id=176 AND index_date_updated > 1459323308) OR ( index_container_id=197 AND index_date_updated > 1460208363) OR ( index_date_updated > 1459323308 AND ( index_container_id NOT IN(4,5,15,19,21,22,28,41,129,130,135,138,139,140,144,147,176,197) ) )) AND ( index_item_id NOT IN (16024,96906,269314,275090,283271,294533,295785,301182,302771,309594,311603,313006,317310,319915,319944,320459,320779,321041,321186,321214,321271,321367,321398,321753,322262,322655,322697,322819,323158,323568) ) ) OR ( ( index_class IN('IPS\\cms\\Records1','IPS\\cms\\Records\\Comment1','IPS\\cms\\Records\\Review1') ) AND (( index_date_updated > 1459323308)) ) OR ( ( index_class IN('IPS\\cms\\Records2','IPS\\cms\\Records\\Comment2','IPS\\cms\\Records\\Review2') ) AND (( index_date_updated > 1459323308)) ) OR ( ( index_class IN('IPS\\blog\\Entry','IPS\\blog\\Entry\\Comment') ) AND (( index_date_updated > 1459323308)) ) OR ( ( index_class IN('IPS\\gallery\\Image','IPS\\gallery\\Image\\Comment','IPS\\gallery\\Image\\Review') ) AND (( index_date_updated > 1459323308)) ) OR ( ( index_class IN('IPS\\downloads\\File','IPS\\downloads\\File\\Comment','IPS\\downloads\\File\\Review') ) AND (( index_date_updated > 1459323308)) ) OR ( ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review') ) AND (( index_date_updated > 1459323308)) ) ) AND ( index_permissions = '*' OR ( FIND_IN_SET(9,index_permissions) OR FIND_IN_SET('m68869',index_permissions) ) ) AND index_hidden=0 AND index_item_id IN(SELECT index_item_id FROM `ibf_core_search_index` AS `sub` WHERE sub.index_class=main.index_class and index_author=68869 AND index_hidden=0 GROUP BY `index_item_id`) ORDER BY index_date_updated DESC LIMIT 0,25;

Is there a solution to this problem ?

Thank you !

 

 

 

[TSP]

Hi, it's difficult to know really. Some queries are just inherently slow, it could be a software/IPS4-problem.

Try to run the queries manually, but put in EXPLAIN at the start, so it'll read "EXPLAIN SELECT ..."

That will give us information about how your MySQL server goes about trying to get a response to these queries and might give us some clues on where the problem is. 

[SecondSight]

Here are some other examples :

 

Quote

# Time: 160821 14:32:35
# User@Host: forums_forums[forums_forums] @ localhost []  Id: 266209
# Query_time: 52.185219  Lock_time: 0.000032 Rows_sent: 1  Rows_examined: 1354
SET timestamp=1471782755;
/*IPS\Content\Search\_Results::count:544*/ SELECT COUNT(*) FROM `ibf_core_search_index` AS `main` WHERE ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) OR index_class='IPS\\forums\\Topic\\Post' OR ( index_class IN('IPS\\cms\\Records1','IPS\\cms\\Records\\Comment1','IPS\\cms\\Records\\Review1') ) OR ( index_class IN('IPS\\cms\\Records2','IPS\\cms\\Records\\Comment2','IPS\\cms\\Records\\Review2') ) OR ( index_class IN('IPS\\blog\\Entry','IPS\\blog\\Entry\\Comment') ) OR ( index_class IN('IPS\\gallery\\Image','IPS\\gallery\\Image\\Comment','IPS\\gallery\\Image\\Review') ) OR ( index_class IN('IPS\\downloads\\File','IPS\\downloads\\File\\Comment','IPS\\downloads\\File\\Review') ) OR ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review') ) OR index_class='IPS\\nexus\\Package\\Review' ) AND MATCH(index_content,index_title) AGAINST ('\"maths+tout+terrain\"' IN BOOLEAN MODE) AND ( index_permissions = '*' OR ( FIND_IN_SET(6,index_permissions) OR FIND_IN_SET('m12909',index_permissions) ) ) AND index_hidden=0;

# Time: 160821 14:32:40
# User@Host: forums_forums[forums_forums] @ localhost []  Id: 266101
# Query_time: 60.011736  Lock_time: 0.000033 Rows_sent: 1  Rows_examined: 1354
SET timestamp=1471782760;
/*IPS\Content\Search\_Results::count:544*/ SELECT COUNT(*) FROM `ibf_core_search_index` AS `main` WHERE ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) OR index_class='IPS\\forums\\Topic\\Post' OR ( index_class IN('IPS\\cms\\Records1','IPS\\cms\\Records\\Comment1','IPS\\cms\\Records\\Review1') ) OR ( index_class IN('IPS\\cms\\Records2','IPS\\cms\\Records\\Comment2','IPS\\cms\\Records\\Review2') ) OR ( index_class IN('IPS\\blog\\Entry','IPS\\blog\\Entry\\Comment') ) OR ( index_class IN('IPS\\gallery\\Image','IPS\\gallery\\Image\\Comment','IPS\\gallery\\Image\\Review') ) OR ( index_class IN('IPS\\downloads\\File','IPS\\downloads\\File\\Comment','IPS\\downloads\\File\\Review') ) OR ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review') ) OR index_class='IPS\\nexus\\Package\\Review' ) AND MATCH(index_content,index_title) AGAINST ('\"maths+tout+terrain\"' IN BOOLEAN MODE) AND ( index_permissions = '*' OR ( FIND_IN_SET(6,index_permissions) OR FIND_IN_SET('m12909',index_permissions) ) ) AND index_hidden=0;

# Time: 160821 14:33:09
# User@Host: forums_forums[forums_forums] @ localhost []  Id: 267032
# Query_time: 58.987939  Lock_time: 0.000043 Rows_sent: 25  Rows_examined: 1379
SET timestamp=1471782789;
/*IPS\Content\Search\Mysql\_Query::search:540*/ SELECT main.*, ((MATCH(index_title) AGAINST ('\"maths+tout+terrain\"' IN BOOLEAN MODE)*5)+(MATCH(index_content,index_title) AGAINST ('\"maths+tout+terrain\"' IN BOOLEAN MODE)))/POWER(( ( UNIX_TIMESTAMP( NOW() ) - ( CASE WHEN index_date_updated <= UNIX_TIMESTAMP( NOW() ) THEN index_date_updated ELSE 0 END )) / 3600 ) + 2,1.5) AS calcscore FROM `ibf_core_search_index` AS `main` WHERE ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) OR index_class='IPS\\forums\\Topic\\Post' OR ( index_class IN('IPS\\cms\\Records1','IPS\\cms\\Records\\Comment1','IPS\\cms\\Records\\Review1') ) OR ( index_class IN('IPS\\cms\\Records2','IPS\\cms\\Records\\Comment2','IPS\\cms\\Records\\Review2') ) OR ( index_class IN('IPS\\blog\\Entry','IPS\\blog\\Entry\\Comment') ) OR ( index_class IN('IPS\\gallery\\Image','IPS\\gallery\\Image\\Comment','IPS\\gallery\\Image\\Review') ) OR ( index_class IN('IPS\\downloads\\File','IPS\\downloads\\File\\Comment','IPS\\downloads\\File\\Review') ) OR ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review') ) OR index_class='IPS\\nexus\\Package\\Review' ) AND MATCH(index_content,index_title) AGAINST ('\"maths+tout+terrain\"' IN BOOLEAN MODE) AND ( index_permissions = '*' OR ( FIND_IN_SET(6,index_permissions) OR FIND_IN_SET('m12909',index_permissions) ) ) AND index_hidden=0 ORDER BY calcscore DESC LIMIT 0,25;

# Time: 160821 14:33:53
# User@Host: forums_forums[forums_forums] @ localhost []  Id: 267032
# Query_time: 44.548817  Lock_time: 0.000027 Rows_sent: 1  Rows_examined: 1354
SET timestamp=1471782833;
/*IPS\Content\Search\_Results::count:544*/ SELECT COUNT(*) FROM `ibf_core_search_index` AS `main` WHERE ( ( index_class IN('IPS\\core\\Statuses\\Status','IPS\\core\\Statuses\\Reply') ) OR index_class='IPS\\forums\\Topic\\Post' OR ( index_class IN('IPS\\cms\\Records1','IPS\\cms\\Records\\Comment1','IPS\\cms\\Records\\Review1') ) OR ( index_class IN('IPS\\cms\\Records2','IPS\\cms\\Records\\Comment2','IPS\\cms\\Records\\Review2') ) OR ( index_class IN('IPS\\blog\\Entry','IPS\\blog\\Entry\\Comment') ) OR ( index_class IN('IPS\\gallery\\Image','IPS\\gallery\\Image\\Comment','IPS\\gallery\\Image\\Review') ) OR ( index_class IN('IPS\\downloads\\File','IPS\\downloads\\File\\Comment','IPS\\downloads\\File\\Review') ) OR ( index_class IN('IPS\\calendar\\Event','IPS\\calendar\\Event\\Comment','IPS\\calendar\\Event\\Review') ) OR index_class='IPS\\nexus\\Package\\Review' ) AND MATCH(index_content,index_title) AGAINST ('\"maths+tout+terrain\"' IN BOOLEAN MODE) AND ( index_permissions = '*' OR ( FIND_IN_SET(6,index_permissions) OR FIND_IN_SET('m12909',index_permissions) ) ) AND index_hidden=0;

I don't understand very well what all this code means... It seems to me that the search is made several times (9 times so far) with the same keywords (in bold, above) ? ! ?

And this makes mysql usage go high...