Description:
We have faced performance issue for the following query on 5.7 which is taking 0.36 seconds and where as MySQL 5.6 its executing within 0.0 seconds
Facing this issue after we upgraded the MySQL from 5.6 to 5.7.
Query : SELECT uniqueId,`fieldLabel`,`fieldType`,`displayOrder`,`identifier`,IFNULL(`initialFormFieldSpecId`,-1) as initialFieldSpecId,IFNULL(`skeletonFormFieldSpecId`,-1) as skeletonFieldSpecId,`isVisible`, trim(case when (`t9`.`fieldType` in (5,6)) then (select group_concat(`t1`.`value`) from `t1` where `t1`.`valueId` IN (-1)) when (`t9`.`fieldType` = 7) then (select `t2`.`customerName` from `t2` where (`t2`.`customerId` = 'false')) when (`t9`.`fieldType` = 15) then (select concat(`t3`.`empFirstName`,' ',`t3`.`empLastName`) from `t3` where (`t3`.`empId` = 'false')) when (`t9`.`fieldType` = 14) then (SELECT GROUP_CONCAT(e.`displayValue`) as displayValue FROM `t4` e WHERE e.`identifier`=1 and e.`entityId`='false' limit 1) when (`t9`.`fieldType` = 17) then (SELECT group_concat(e.`displayValue`) FROM `t4` e WHERE e.`identifier`=1 and e.`entityId` IN (-1))when (`t9`.`fieldType` = 4) then (if('true'='false','yes','no')) when (`t9`.`fieldType` = 24) then (select customerTypeName from t5 where customerTypeId='false' limit 1) when (`t9`.`fieldType` = 30) then (SELECT group_concat(`t2`.`customerName`) FROM `t2` where `t2`.`customerId` IN (-1)) when (`t9`.`fieldType` = 31) then (select t7.`territoryName` FROM `t7` where (t7.`territoryId` = 'false'))when (`t9`.`fieldType` = 32) then (select t6.`customEntityName` FROM `t6` where (t6.`customEntityId` = 'false'))when (`t9`.`fieldType` = 25) then (SELECT IFNULL(concat(f.`formId`,'-',group_concat(fi.`identifier`)),f.formId) FROM t8 f LEFT JOIN (select `FormFields`.`formId` AS `formId`,group_concat(`FormFields`.`displayValue` separator ',') AS `identifier` from `FormFields` where (`FormFields`.`identifier` = 1) and formId = 'false' group by formId) AS fi ON f.formId=fi.formId WHERE f.`formId`= 'false') else 'false' end) as displayValue FROM `t9` WHERE `fieldSpecId`=1957147;
We tried changed optimizer_search_depth values on MySQL 5.7, but no luck.
How to repeat:
Please find the query profiling for mysql 5.6 and 5.7 below
Mysql 5.6
mysql> SHOW PROFILE SOURCE FOR QUERY 1;
+--------------------------------+----------+-----------------------+------------------+-------------+
| Status | Duration | Source_function | Source_file | Source_line |
+--------------------------------+----------+-----------------------+------------------+-------------+
| starting | 0.036983 | NULL | NULL | NULL |
| Waiting for query cache lock | 0.000006 | try_lock | sql_cache.cc | 668 |
| Waiting on query cache mutex | 0.000003 | try_lock | sql_cache.cc | 672 |
| init | 0.000002 | try_lock | sql_cache.cc | 668 |
| checking query cache for query | 0.000261 | send_result_to_client | sql_cache.cc | 1902 |
| checking permissions | 0.000004 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000001 | check_access | sql_parse.cc | 5952 |
| checking permissions | 0.000005 | check_access | sql_parse.cc | 5952 |
| Opening tables | 0.000127 | open_tables | sql_base.cc | 5270 |
| init | 0.000102 | mysql_prepare_select | sql_select.cc | 1058 |
| System lock | 0.000019 | mysql_lock_tables | lock.cc | 313 |
| Waiting for query cache lock | 0.000002 | try_lock | sql_cache.cc | 668 |
| Waiting on query cache mutex | 0.000003 | try_lock | sql_cache.cc | 672 |
| System lock | 0.000101 | try_lock | sql_cache.cc | 668 |
| optimizing | 0.000006 | optimize | sql_optimizer.cc | 146 |
| statistics | 0.000040 | optimize | sql_optimizer.cc | 391 |
| preparing | 0.000005 | optimize | sql_optimizer.cc | 514 |
| executing | 0.000002 | exec | sql_executor.cc | 117 |
| Sending data | 0.000016 | exec | sql_executor.cc | 197 |
| end | 0.000005 | mysql_execute_select | sql_select.cc | 1113 |
| query end | 0.000004 | mysql_execute_command | sql_parse.cc | 5619 |
| closing tables | 0.000003 | mysql_execute_command | sql_parse.cc | 5699 |
| removing tmp table | 0.000003 | free_tmp_table | sql_tmp_table.cc | 1880 |
| closing tables | 0.000015 | free_tmp_table | sql_tmp_table.cc | 1917 |
| freeing items | 0.000013 | mysql_parse | sql_parse.cc | 7244 |
| Waiting for query cache lock | 0.000002 | try_lock | sql_cache.cc | 668 |
| Waiting on query cache mutex | 0.000002 | try_lock | sql_cache.cc | 672 |
| freeing items | 0.000018 | try_lock | sql_cache.cc | 668 |
| Waiting for query cache lock | 0.000002 | try_lock | sql_cache.cc | 668 |
| Waiting on query cache mutex | 0.000001 | try_lock | sql_cache.cc | 672 |
| freeing items | 0.000002 | try_lock | sql_cache.cc | 668 |
| storing result in query cache | 0.000002 | end_of_result | sql_cache.cc | 1239 |
| cleaning up | 0.000014 | dispatch_command | sql_parse.cc | 1980 |
+--------------------------------+----------+-----------------------+------------------+-------------+
42 rows in set, 1 warning (0.00 sec)
Mysql 5.7
mysql> SHOW PROFILE SOURCE FOR QUERY 1;
+----------------------+----------+-----------------------+----------------------+-------------+
| Status | Duration | Source_function | Source_file | Source_line |
+----------------------+----------+-----------------------+----------------------+-------------+
| starting | 0.000382 | NULL | NULL | NULL |
| checking permissions | 0.000007 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 |
| checking permissions | 0.000005 | check_access | sql_authorization.cc | 817 |
| Opening tables | 0.000394 | open_tables | sql_base.cc | 5885 |
| init | 0.000215 | handle_query | sql_select.cc | 128 |
| System lock | 0.000019 | mysql_lock_tables | lock.cc | 330 |
| optimizing | 0.000011 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000081 | optimize | sql_optimizer.cc | 393 |
| preparing | 0.000012 | optimize | sql_optimizer.cc | 501 |
| optimizing | 0.000003 | optimize | sql_optimizer.cc | 158 |
| optimizing | 0.000005 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000213 | optimize | sql_optimizer.cc | 393 |
| preparing | 0.000185 | optimize | sql_optimizer.cc | 501 |
| executing | 0.000004 | exec | sql_executor.cc | 126 |
| Sending data | 0.282652 | exec | sql_executor.cc | 202 |
| statistics | 0.000068 | optimize | sql_optimizer.cc | 393 |
| optimizing | 0.000006 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000024 | optimize | sql_optimizer.cc | 393 |
| optimizing | 0.000005 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000033 | optimize | sql_optimizer.cc | 393 |
| optimizing | 0.000007 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000034 | optimize | sql_optimizer.cc | 393 |
| optimizing | 0.000004 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000015 | optimize | sql_optimizer.cc | 393 |
| optimizing | 0.000008 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000097 | optimize | sql_optimizer.cc | 393 |
| preparing | 0.000119 | optimize | sql_optimizer.cc | 501 |
| optimizing | 0.000007 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000039 | optimize | sql_optimizer.cc | 393 |
| preparing | 0.000132 | optimize | sql_optimizer.cc | 501 |
| optimizing | 0.000010 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000031 | optimize | sql_optimizer.cc | 393 |
| optimizing | 0.000007 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000029 | optimize | sql_optimizer.cc | 393 |
| optimizing | 0.000005 | optimize | sql_optimizer.cc | 158 |
| statistics | 0.000024 | optimize | sql_optimizer.cc | 393 |
| executing | 0.000003 | exec | sql_executor.cc | 126 |
| Sending data | 0.000038 | exec | sql_executor.cc | 202 |
| end | 0.000005 | handle_query | sql_select.cc | 207 |
| query end | 0.000015 | mysql_execute_command | sql_parse.cc | 5265 |
| removing tmp table | 0.000009 | free_tmp_table | sql_tmp_table.cc | 2423 |
| query end | 0.000005 | free_tmp_table | sql_tmp_table.cc | 2460 |
| removing tmp table | 0.000004 | free_tmp_table | sql_tmp_table.cc | 2423 |
| query end | 0.000002 | free_tmp_table | sql_tmp_table.cc | 2460 |
| removing tmp table | 0.000003 | free_tmp_table | sql_tmp_table.cc | 2423 |
| query end | 0.000003 | free_tmp_table | sql_tmp_table.cc | 2460 |
| closing tables | 0.000005 | mysql_execute_command | sql_parse.cc | 5344 |
| removing tmp table | 0.000055 | free_tmp_table | sql_tmp_table.cc | 2423 |
| closing tables | 0.000028 | free_tmp_table | sql_tmp_table.cc | 2460 |
| freeing items | 0.000066 | mysql_parse | sql_parse.cc | 5965 |
| cleaning up | 0.000022 | dispatch_command | sql_parse.cc | 1991 |
+----------------------+----------+-----------------------+----------------------+-------------+
61 rows in set, 1 warning (0.00 sec)
In profiling sending data is taking more time in mysql 5.7
Explain plan is same for both 5.6 and 5.7.
We created one index on 5.7 and response time is now 0.05 secs.
We also tried the optimized hint which is not helping us to improve the performance, no luck.
Description: We have faced performance issue for the following query on 5.7 which is taking 0.36 seconds and where as MySQL 5.6 its executing within 0.0 seconds Facing this issue after we upgraded the MySQL from 5.6 to 5.7. Query : SELECT uniqueId,`fieldLabel`,`fieldType`,`displayOrder`,`identifier`,IFNULL(`initialFormFieldSpecId`,-1) as initialFieldSpecId,IFNULL(`skeletonFormFieldSpecId`,-1) as skeletonFieldSpecId,`isVisible`, trim(case when (`t9`.`fieldType` in (5,6)) then (select group_concat(`t1`.`value`) from `t1` where `t1`.`valueId` IN (-1)) when (`t9`.`fieldType` = 7) then (select `t2`.`customerName` from `t2` where (`t2`.`customerId` = 'false')) when (`t9`.`fieldType` = 15) then (select concat(`t3`.`empFirstName`,' ',`t3`.`empLastName`) from `t3` where (`t3`.`empId` = 'false')) when (`t9`.`fieldType` = 14) then (SELECT GROUP_CONCAT(e.`displayValue`) as displayValue FROM `t4` e WHERE e.`identifier`=1 and e.`entityId`='false' limit 1) when (`t9`.`fieldType` = 17) then (SELECT group_concat(e.`displayValue`) FROM `t4` e WHERE e.`identifier`=1 and e.`entityId` IN (-1))when (`t9`.`fieldType` = 4) then (if('true'='false','yes','no')) when (`t9`.`fieldType` = 24) then (select customerTypeName from t5 where customerTypeId='false' limit 1) when (`t9`.`fieldType` = 30) then (SELECT group_concat(`t2`.`customerName`) FROM `t2` where `t2`.`customerId` IN (-1)) when (`t9`.`fieldType` = 31) then (select t7.`territoryName` FROM `t7` where (t7.`territoryId` = 'false'))when (`t9`.`fieldType` = 32) then (select t6.`customEntityName` FROM `t6` where (t6.`customEntityId` = 'false'))when (`t9`.`fieldType` = 25) then (SELECT IFNULL(concat(f.`formId`,'-',group_concat(fi.`identifier`)),f.formId) FROM t8 f LEFT JOIN (select `FormFields`.`formId` AS `formId`,group_concat(`FormFields`.`displayValue` separator ',') AS `identifier` from `FormFields` where (`FormFields`.`identifier` = 1) and formId = 'false' group by formId) AS fi ON f.formId=fi.formId WHERE f.`formId`= 'false') else 'false' end) as displayValue FROM `t9` WHERE `fieldSpecId`=1957147; We tried changed optimizer_search_depth values on MySQL 5.7, but no luck. How to repeat: Please find the query profiling for mysql 5.6 and 5.7 below Mysql 5.6 mysql> SHOW PROFILE SOURCE FOR QUERY 1; +--------------------------------+----------+-----------------------+------------------+-------------+ | Status | Duration | Source_function | Source_file | Source_line | +--------------------------------+----------+-----------------------+------------------+-------------+ | starting | 0.036983 | NULL | NULL | NULL | | Waiting for query cache lock | 0.000006 | try_lock | sql_cache.cc | 668 | | Waiting on query cache mutex | 0.000003 | try_lock | sql_cache.cc | 672 | | init | 0.000002 | try_lock | sql_cache.cc | 668 | | checking query cache for query | 0.000261 | send_result_to_client | sql_cache.cc | 1902 | | checking permissions | 0.000004 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000002 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000001 | check_access | sql_parse.cc | 5952 | | checking permissions | 0.000005 | check_access | sql_parse.cc | 5952 | | Opening tables | 0.000127 | open_tables | sql_base.cc | 5270 | | init | 0.000102 | mysql_prepare_select | sql_select.cc | 1058 | | System lock | 0.000019 | mysql_lock_tables | lock.cc | 313 | | Waiting for query cache lock | 0.000002 | try_lock | sql_cache.cc | 668 | | Waiting on query cache mutex | 0.000003 | try_lock | sql_cache.cc | 672 | | System lock | 0.000101 | try_lock | sql_cache.cc | 668 | | optimizing | 0.000006 | optimize | sql_optimizer.cc | 146 | | statistics | 0.000040 | optimize | sql_optimizer.cc | 391 | | preparing | 0.000005 | optimize | sql_optimizer.cc | 514 | | executing | 0.000002 | exec | sql_executor.cc | 117 | | Sending data | 0.000016 | exec | sql_executor.cc | 197 | | end | 0.000005 | mysql_execute_select | sql_select.cc | 1113 | | query end | 0.000004 | mysql_execute_command | sql_parse.cc | 5619 | | closing tables | 0.000003 | mysql_execute_command | sql_parse.cc | 5699 | | removing tmp table | 0.000003 | free_tmp_table | sql_tmp_table.cc | 1880 | | closing tables | 0.000015 | free_tmp_table | sql_tmp_table.cc | 1917 | | freeing items | 0.000013 | mysql_parse | sql_parse.cc | 7244 | | Waiting for query cache lock | 0.000002 | try_lock | sql_cache.cc | 668 | | Waiting on query cache mutex | 0.000002 | try_lock | sql_cache.cc | 672 | | freeing items | 0.000018 | try_lock | sql_cache.cc | 668 | | Waiting for query cache lock | 0.000002 | try_lock | sql_cache.cc | 668 | | Waiting on query cache mutex | 0.000001 | try_lock | sql_cache.cc | 672 | | freeing items | 0.000002 | try_lock | sql_cache.cc | 668 | | storing result in query cache | 0.000002 | end_of_result | sql_cache.cc | 1239 | | cleaning up | 0.000014 | dispatch_command | sql_parse.cc | 1980 | +--------------------------------+----------+-----------------------+------------------+-------------+ 42 rows in set, 1 warning (0.00 sec) Mysql 5.7 mysql> SHOW PROFILE SOURCE FOR QUERY 1; +----------------------+----------+-----------------------+----------------------+-------------+ | Status | Duration | Source_function | Source_file | Source_line | +----------------------+----------+-----------------------+----------------------+-------------+ | starting | 0.000382 | NULL | NULL | NULL | | checking permissions | 0.000007 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000002 | check_access | sql_authorization.cc | 817 | | checking permissions | 0.000005 | check_access | sql_authorization.cc | 817 | | Opening tables | 0.000394 | open_tables | sql_base.cc | 5885 | | init | 0.000215 | handle_query | sql_select.cc | 128 | | System lock | 0.000019 | mysql_lock_tables | lock.cc | 330 | | optimizing | 0.000011 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000081 | optimize | sql_optimizer.cc | 393 | | preparing | 0.000012 | optimize | sql_optimizer.cc | 501 | | optimizing | 0.000003 | optimize | sql_optimizer.cc | 158 | | optimizing | 0.000005 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000213 | optimize | sql_optimizer.cc | 393 | | preparing | 0.000185 | optimize | sql_optimizer.cc | 501 | | executing | 0.000004 | exec | sql_executor.cc | 126 | | Sending data | 0.282652 | exec | sql_executor.cc | 202 | | statistics | 0.000068 | optimize | sql_optimizer.cc | 393 | | optimizing | 0.000006 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000024 | optimize | sql_optimizer.cc | 393 | | optimizing | 0.000005 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000033 | optimize | sql_optimizer.cc | 393 | | optimizing | 0.000007 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000034 | optimize | sql_optimizer.cc | 393 | | optimizing | 0.000004 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000015 | optimize | sql_optimizer.cc | 393 | | optimizing | 0.000008 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000097 | optimize | sql_optimizer.cc | 393 | | preparing | 0.000119 | optimize | sql_optimizer.cc | 501 | | optimizing | 0.000007 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000039 | optimize | sql_optimizer.cc | 393 | | preparing | 0.000132 | optimize | sql_optimizer.cc | 501 | | optimizing | 0.000010 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000031 | optimize | sql_optimizer.cc | 393 | | optimizing | 0.000007 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000029 | optimize | sql_optimizer.cc | 393 | | optimizing | 0.000005 | optimize | sql_optimizer.cc | 158 | | statistics | 0.000024 | optimize | sql_optimizer.cc | 393 | | executing | 0.000003 | exec | sql_executor.cc | 126 | | Sending data | 0.000038 | exec | sql_executor.cc | 202 | | end | 0.000005 | handle_query | sql_select.cc | 207 | | query end | 0.000015 | mysql_execute_command | sql_parse.cc | 5265 | | removing tmp table | 0.000009 | free_tmp_table | sql_tmp_table.cc | 2423 | | query end | 0.000005 | free_tmp_table | sql_tmp_table.cc | 2460 | | removing tmp table | 0.000004 | free_tmp_table | sql_tmp_table.cc | 2423 | | query end | 0.000002 | free_tmp_table | sql_tmp_table.cc | 2460 | | removing tmp table | 0.000003 | free_tmp_table | sql_tmp_table.cc | 2423 | | query end | 0.000003 | free_tmp_table | sql_tmp_table.cc | 2460 | | closing tables | 0.000005 | mysql_execute_command | sql_parse.cc | 5344 | | removing tmp table | 0.000055 | free_tmp_table | sql_tmp_table.cc | 2423 | | closing tables | 0.000028 | free_tmp_table | sql_tmp_table.cc | 2460 | | freeing items | 0.000066 | mysql_parse | sql_parse.cc | 5965 | | cleaning up | 0.000022 | dispatch_command | sql_parse.cc | 1991 | +----------------------+----------+-----------------------+----------------------+-------------+ 61 rows in set, 1 warning (0.00 sec) In profiling sending data is taking more time in mysql 5.7 Explain plan is same for both 5.6 and 5.7. We created one index on 5.7 and response time is now 0.05 secs. We also tried the optimized hint which is not helping us to improve the performance, no luck.