query with bad performance after migration to mysql 5.6
Hi
i have a problem with a query after migration on mysql5.6
on mysql 5.5 all works fine the query is executed in 37 millisecs ,
the same query on 5.6 is too long 29 seconds!!!
I havd replicated my envs , so i have
2 databases (5.5.46 and 5.6.25 ) with the same data
and the same configuration parameters
the query is:
SELECT messaggio.id, messaggio.data, allegati.id
FROM (
select m.id from messaggio m
WHERE m.idarticolo='repnews_271330' AND m.idpadre=0
AND m.pubblica=1 ORDER BY m.data DESC LIMIT 50
) as m_padre
join messaggio on (m_padre.id=messaggio.idpadre OR m_padre.id=messaggio.id)
left join allegati on messaggio.id = allegati.idpost
ORDER BY messaggio.data DESC, messaggio.id desc, allegati.id asc;
explain on 5.5 is:
+----+-------------+------------+------+-------------------------------------------------------+----------------+---------+----------------------------+---------+-------------------------------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+------------+------+-------------------------------------------------------+----------------+---------+----------------------------+---------+-------------------------------------------------+
| 1 | PRIMARY | <derived2> | ALL | NULL | NULL | NULL | NULL | 27 | Using temporary; Using filesort |
| 1 | PRIMARY | messaggio | ALL | PRIMARY,idpadre,idpadrepubblica_idx,ididpadrepubblica | NULL | NULL | NULL | 2357872 | Range checked for each record (index map: 0x65) |
| 1 | PRIMARY | allegati | ref | idpost_idx | idpost_idx | 5 | DROPME_ts_mms.messaggio.id | 1 | Using index |
| 2 | DERIVED | m | ALL | idpadre,idpadrepubblica_idx,idarticolo_idx | idarticolo_idx | 130 | | 2357872 | Using where; Using filesort |
+----+-------------+------------+------+-------------------------------------------------------+----------------+---------+----------------------------+---------+-------------------------------------------------+
explain on 5.6:
+----+-------------+------------+------+-------------------------------------------------------+----------------+---------+------------------------------+---------+----------------------------------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+------------+------+-------------------------------------------------------+----------------+---------+------------------------------+---------+----------------------------------------------------+
| 1 | PRIMARY | messaggio | ALL | PRIMARY,idpadre,idpadrepubblica_idx,ididpadrepubblica | NULL | NULL | NULL | 2445095 | Using temporary; Using filesort |
| 1 | PRIMARY | allegati | ref | idpost_idx | idpost_idx | 5 | DROPME_ts_mms56.messaggio.id | 1 | Using index |
| 1 | PRIMARY | <derived2> | ALL | NULL | NULL | NULL | NULL | 26 | Using where; Using join buffer (Block Nested Loop) |
| 2 | DERIVED | m | ref | idpadre,idpadrepubblica_idx,idarticolo_idx | idarticolo_idx | 130 | const | 26 | Using index condition; Using where; Using filesort |
+----+-------------+------------+------+-------------------------------------------------------+----------------+---------+------------------------------+---------+----------------------------------------------------+
-- profioling the query i see:
on 5.5
mysql> show profiles\G;
*************************** 1. row ***************************
Query_ID: 1
Duration: 0.00376525
Query: SELECT messaggio.id, messaggio.data, allegati.id
FROM (
select m.id from messaggio m
WHERE m.idarticolo='repnews_271330' AND m.idpadre=0
AND m.pubblica=1
ORDER BY m.data DESC
LIMIT 50
) as m_padre
join messaggio on (m_padre.id=messaggio.idpadre OR m_padre.id=messag
1 row in set (0.00 sec)
ERROR:
No query specified
mysql> select min(seq) seq,state,count(*) numb_ops,
-> round(sum(duration),5) sum_dur, round(avg(duration),5) avg_dur,
-> round(sum(cpu_user),5) sum_cpu, round(avg(cpu_user),5) avg_cpu
-> from information_schema.profiling
-> where query_id = 1
-> group by state
-> order by seq;
+------+----------------------+----------+---------+---------+---------+---------+
| seq | state | numb_ops | sum_dur | avg_dur | sum_cpu | avg_cpu |
+------+----------------------+----------+---------+---------+---------+---------+
| 2 | starting | 1 | 0.00018 | 0.00018 | 0.00016 | 0.00016 |
| 3 | checking permissions | 3 | 0.00002 | 0.00001 | 0.00001 | 0.00000 |
| 6 | Opening tables | 1 | 0.00005 | 0.00005 | 0.00004 | 0.00004 |
| 7 | System lock | 1 | 0.00009 | 0.00009 | 0.00009 | 0.00009 |
| 8 | optimizing | 2 | 0.00003 | 0.00002 | 0.00003 | 0.00002 |
| 9 | statistics | 2 | 0.00020 | 0.00010 | 0.00020 | 0.00010 |
| 10 | preparing | 2 | 0.00007 | 0.00003 | 0.00006 | 0.00003 |
| 11 | executing | 2 | 0.00001 | 0.00001 | 0.00001 | 0.00000 |
| 12 | Sorting result | 2 | 0.00021 | 0.00011 | 0.00021 | 0.00010 |
| 13 | Sending data | 2 | 0.00007 | 0.00004 | 0.00007 | 0.00003 |
| 14 | init | 1 | 0.00003 | 0.00003 | 0.00003 | 0.00003 |
| 18 | Creating tmp table | 1 | 0.00003 | 0.00003 | 0.00003 | 0.00003 |
| 20 | Copying to tmp table | 1 | 0.00266 | 0.00266 | 0.00258 | 0.00258 |
| 23 | end | 2 | 0.00001 | 0.00001 | 0.00001 | 0.00000 |
| 24 | removing tmp table | 2 | 0.00002 | 0.00001 | 0.00001 | 0.00001 |
| 26 | query end | 1 | 0.00001 | 0.00001 | 0.00001 | 0.00001 |
| 27 | closing tables | 2 | 0.00002 | 0.00001 | 0.00002 | 0.00001 |
| 30 | freeing items | 1 | 0.00004 | 0.00004 | 0.00002 | 0.00002 |
| 31 | logging slow query | 1 | 0.00001 | 0.00001 | 0.00001 | 0.00001 |
| 32 | cleaning up | 1 | 0.00001 | 0.00001 | 0.00001 | 0.00001 |
+------+----------------------+----------+---------+---------+---------+---------+
20 rows in set (0.00 sec)
-- on 5.6
mysql> show profiles\G;
*************************** 1. row ***************************
Query_ID: 1
Duration: 28.96773375
Query: SELECT messaggio.id, messaggio.data, allegati.id
FROM (
select m.id from messaggio m
WHERE m.idarticolo='repnews_271330' AND m.idpadre=0
AND m.pubblica=1
ORDER BY m.data DESC
LIMIT 50
) as m_padre
join messaggio on (m_padre.id=messaggio.idpadre OR m_padre.id=messag
1 row in set, 1 warning (0.00 sec)
ERROR:
No query specified
mysql> select min(seq) seq,state,count(*) numb_ops,
-> round(sum(duration),5) sum_dur, round(avg(duration),5) avg_dur,
-> round(sum(cpu_user),5) sum_cpu, round(avg(cpu_user),5) avg_cpu
-> from information_schema.profiling
-> where query_id = 1
-> group by state
-> order by seq;
+------+----------------------+----------+----------+----------+----------+----------+
| seq | state | numb_ops | sum_dur | avg_dur | sum_cpu | avg_cpu |
+------+----------------------+----------+----------+----------+----------+----------+
| 2 | starting | 1 | 0.00020 | 0.00020 | 0.00017 | 0.00017 |
| 3 | checking permissions | 3 | 0.00002 | 0.00001 | 0.00001 | 0.00000 |
| 6 | Opening tables | 1 | 0.00010 | 0.00010 | 0.00010 | 0.00010 |
| 7 | init | 1 | 0.00003 | 0.00003 | 0.00003 | 0.00003 |
| 8 | System lock | 1 | 0.00002 | 0.00002 | 0.00002 | 0.00002 |
| 9 | optimizing | 2 | 0.00003 | 0.00001 | 0.00002 | 0.00001 |
| 11 | statistics | 2 | 0.00026 | 0.00013 | 0.00025 | 0.00013 |
| 12 | preparing | 2 | 0.00008 | 0.00004 | 0.00007 | 0.00004 |
| 13 | Sorting result | 2 | 0.00003 | 0.00001 | 0.00002 | 0.00001 |
| 16 | Creating tmp table | 1 | 0.00003 | 0.00003 | 0.00002 | 0.00002 |
| 18 | executing | 2 | 0.00003 | 0.00001 | 0.00002 | 0.00001 |
| 19 | Sending data | 2 | 0.00007 | 0.00003 | 0.00006 | 0.00003 |
| 22 | Creating sort index | 2 | 28.96662 | 14.48331 | 28.96593 | 14.48296 |
| 24 | end | 2 | 0.00002 | 0.00001 | 0.00001 | 0.00001 |
| 25 | removing tmp table | 2 | 0.00002 | 0.00001 | 0.00002 | 0.00001 |
| 27 | query end | 1 | 0.00001 | 0.00001 | 0.00001 | 0.00001 |
| 28 | closing tables | 2 | 0.00003 | 0.00002 | 0.00003 | 0.00001 |
| 31 | freeing items | 1 | 0.00005 | 0.00005 | 0.00003 | 0.00003 |
| 32 | logging slow query | 1 | 0.00009 | 0.00009 | 0.00005 | 0.00005 |
| 33 | cleaning up | 1 | 0.00003 | 0.00003 | 0.00002 | 0.00002 |
+------+----------------------+----------+----------+----------+----------+----------+
20 rows in set (0.00 sec)
so i see
22 | Creating sort index | 2 | 28.96662 | 14.48331 | 28.96593 | 14.48296 |
why all this time on this operation ??
Any suggest
Regards
Walter