MySQL Forums
Forum List  »  Performance

query with bad performance after migration to mysql 5.6
Posted by: walter verdelocco
Date: December 04, 2015 05:35AM

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

Options: ReplyQuote


Subject
Views
Written By
Posted
query with bad performance after migration to mysql 5.6
2641
December 04, 2015 05:35AM


Sorry, you can't reply to this topic. It has been closed.

Content reproduced on this site is the property of the respective copyright holders. It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.