Description:
Starting from MySQL 8.0.29, many queries with JOINS, specifically using eq_ref iterator/access perform very poorly. We are seeing regressions for many queries. The regression can be as bad as 2241.8%. I have been chasing this at Percona for a long time and was finally able to find the commit causing regression
Because of such 'slow' queries, they can bring the performance of entire MySQL server down. How?
If there is a long running query with a read view assigned, the purge cannot proceed further. The history list length will keep increasing and many other reads will start building old versions of records.
READ-COMMITTED isolation also will not help.
The source of regression from 8.0.29 is this:
https://github.com/mysql/mysql-server/commit/4a17d55a700b7bb5c1b91fb1bf44f6d162ffc44a
--
Bug#33491183: Wrong query result using select Union All
Bug#33503357: comparing a `bigint` value with an identical `bigint unsigned` value fails
Bug#33634109: hypergraph: Unstable results from TPC-H Q2
Bug#33674441: Wrong result with outer join and streaming aggregation
Aggregated queries that performed an index lookup (eq_ref) could in
some cases return wrong results. This is a regression after
bug#31790217 (REWRITE STREAMING AGGREGATION).
The bug is only seen if the execution plan used streaming aggregation
instead of aggregation in temporary tables. (Since streaming
aggregation currently is the only aggregation strategy supported by
the hypergraph optimizer, the bug is seen more frequently with the
hypergraph optimizer. But the bug also affects the old optimizer.)
The issue is that AggregateIterator and EQRefIterator touch the record
buffer (table->record[0]) of the same TABLE object. EQRefIterator has
a mechanism for caching the last key that it was called with, in order
to avoid a new index lookup if it is called again with the same key.
It can do this on the assumption that the contents of the record
buffer still point to the row with the requested key. However,
AggregateIterator's modifying of the same record buffer breaks this
assumption. Specifically, when AggregateIterator reads a row and
detects that it has come to the next group, it modifies the record
buffers of the underlying scans to point into an arbitrary row in the
previous group. This means that the EQRefIterator below it cannot rely
on its record buffer to point to the last row it returned, and it
cannot reuse those values even if the key is the same as in the
previous call.
This patch fixes the bug in the hypergraph optimizer by adding a
STREAM access path just below the AGGREGATE access path, if there is
an EQ_REF. This makes the AggregateIterator work on a different TABLE
object than the EQRefIterator, so that it doesn't interfere with
EQRefIterator's caching.
A similar fix could have been applied to the old optimizer. But adding
intermediate temporary tables is harder in the old optimizer, so the
patch simply disables EQ_REF caching below AGGREGATE nodes in the old
optimizer for now.
Change-Id: Idd7bda5dfca24052bfc593f036a95e13f9bf1644
---
Regression is due to this commit. May be related to disabling EQ_REF caching.
In the below section, I have some proofs to show the regressions
How to repeat:
--source include/count_sessions.inc
--connect (con1, localhost, root,,)
--connect (con2, localhost, root,,)
create table t1(a INT NOT NULL AUTO_INCREMENT PRIMARY KEY, b INT, KEY(b));
--disable_query_log
--let $i=1
while ($i < 250) {
--eval insert into t1 values (NULL, $i)
--inc $i
}
--enable_query_log
insert into t1 select NULL,b from t1;
insert into t1 select NULL,b from t1;
insert into t1 select NULL,b from t1;
insert into t1 select NULL,b from t1;
insert into t1 select NULL,b from t1;
select count(*) from t1;
create table t2(b INT NOT NULL PRIMARY KEY, c INT);
--disable_query_log
--let $i=1
while ($i < 250) {
--eval insert into t2 values ($i, $i)
--inc $i
}
--enable_query_log
create table t2_src(b INT, c INT);
INSERT INTO t2_src SELECT * FROM t2;
INSERT INTO t2_src SELECT * FROM t2;
INSERT INTO t2_src SELECT * FROM t2;
INSERT INTO t2_src SELECT * FROM t2;
INSERT INTO t2_src SELECT * FROM t2;
INSERT INTO t2_src SELECT * FROM t2;
create table t3(b INT NOT NULL AUTO_INCREMENT PRIMARY KEY, d INT);
--disable_query_log
--let $i=1
while ($i < 250) {
--eval insert into t3 values (NULL, $i)
--inc $i
}
--enable_query_log
connection con1;
begin;
replace into t2 select * from t2_src;
connection con2;
#explain select b, count(*) as count_bs from t1 left join t2 using (b) left join t3 using (b) group by b;
#explain format=tree select b, count(*) as count_bs from t1 left join t2 using (b) left join t3 using (b) group by b;
#show status like '%Handler%';
--let $handler_key_start=query_get_value(SHOW STATUS LIKE 'Handler_read_key',Value,1)
set debug='+d,ib_sel';
select b, count(*) as count_bs from t1 left join t2 using (b) left join t3 using (b) group by b;
set debug='-d,ib_sel';
--let $handler_key_end=query_get_value(SHOW STATUS LIKE 'Handler_read_key',Value,1)
--expr $res= $handler_key_end - $handler_key_start
#show status like '%Handler%';
assert($res <= 500); #250 rows from t2, 250 rows from t3
connection con1;
commit;
connection default;
--disconnect con1
--disconnect con2
--source include/wait_until_count_sessions.inc
DROP TABLE t1,t2,t3;
----
Asssertion will fail because we do more index reads than the number of records in t2 and t3.
If you revert commit 4a17d55a700b7bb5c1b91fb1bf44f6d162ffc44a, execute the same testcase it will pass.
----
Also apply this patch to trace the number of reads by the query and number of row versions built by InnoDB
diff --git a/storage/innobase/row/row0sel.cc b/storage/innobase/row/row0sel.cc
index a41e63d98ca..38e5cd12367 100644
--- a/storage/innobase/row/row0sel.cc
+++ b/storage/innobase/row/row0sel.cc
@@ -4358,6 +4358,12 @@ dberr_t row_search_mvcc(byte *buf, page_cur_mode_t mode,
DBUG_TRACE;
dict_index_t *index = prebuilt->index;
+
+ DBUG_EXECUTE_IF("ib_sel", ib::info() << "SEARCH Table: " << index->table->name.m_name
+ << " Index: " << index->name();
+ dtuple_print(stderr, prebuilt->search_tuple);
+ ib::info() << "------------------------------";);
+
bool comp = dict_table_is_comp(index->table);
const dtuple_t *search_tuple = prebuilt->search_tuple;
btr_pcur_t *pcur = prebuilt->pcur;
diff --git a/storage/innobase/row/row0vers.cc b/storage/innobase/row/row0vers.cc
index b9868057ee8..efd0d70c6b0 100644
--- a/storage/innobase/row/row0vers.cc
+++ b/storage/innobase/row/row0vers.cc
@@ -1278,6 +1278,7 @@ dberr_t row_vers_build_for_consistent_read(
version = rec;
+ uint32_t num_versions = 0;
for (;;) {
mem_heap_t *prev_heap = heap;
@@ -1334,8 +1335,11 @@ dberr_t row_vers_build_for_consistent_read(
}
version = prev_version;
+ ++num_versions;
}
+ ib::info() << "VERSIONS: Table: " << index->table->name.m_name << " index: " << index->name()
+ << " row_versions: " << num_versions;
mem_heap_free(heap);
return err;
--
-----
Without revert, mysql 8.0.29 + trace reads patch
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t1" var/log/mysqld.1.err |wc -l
7969
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t2" var/log/mysqld.1.err |wc -l
7968
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t3" var/log/mysqld.1.err |wc -l
7968
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "row_versions" var/log/mysqld.1.err |awk '{ sum += $12 } END { print sum }'
39840
-----
After reverting problematic commit: 4a17d55a700b7bb5c1b91fb1bf44f6d162ffc44a
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t1" var/log/mysqld.1.err |wc -l
7969
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t2" var/log/mysqld.1.err |wc -l
249
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t2" var/log/mysqld.1.err |wc -l
249
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t3" var/log/mysqld.1.err |wc -l
249
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "row_versions" var/log/mysqld.1.err |awk '{ sum += $12 } END { print sum }'
1245
------
-----
Without revert, mysql 8.0.29 + trace reads patch
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t1" var/log/mysqld.1.err |wc -l
7969
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t2" var/log/mysqld.1.err |wc -l
7968
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t3" var/log/mysqld.1.err |wc -l
7968
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "row_versions" var/log/mysqld.1.err |awk '{ sum += $12 } END { print sum }'
39840
-----
Total reads for query: 7969 + 7968 + 7968 = 23805
Total row versions for query: 38840
After reverting problematic commit: 4a17d55a700b7bb5c1b91fb1bf44f6d162ffc44a
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t1" var/log/mysqld.1.err |wc -l
7969
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t2" var/log/mysqld.1.err |wc -l
249
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "Table: test/t3" var/log/mysqld.1.err |wc -l
249
satya@satya-ThinkPad-X1-Extreme-Gen-3:~/WORK/mysql-8.0.29/bld/mysql-test$ grep "row_versions" var/log/mysqld.1.err |awk '{ sum += $12 } END { print sum }'
1245
Total reads for query: 7969 + 7968 + 7968 = 8467
Total row versions for query: 1245
------
How much is penalty because of regression?
------------------------------------------
Regression in reads: 358%
regression in row versions: 3019.67%
This roughly translates to 2000% slower. Unfortunately, I cannot give the query that
shows this % slower with a query using release builds. It has some customer data.
But I am sure, the above data and commit is sufficient enough to prove there is
regression from MySQL 8.0.29 onwards
Suggested fix:
Unfortunately, I don't know Optimizer code well. I think disabling eq_ref cache translated to more reads in tables to be joined.
As you saw, we read the t2 and t3 many times ( 7968 times each). The actual number of rows is just 250.
This should be avoided.
one row read can translate to building X versions of the row based on read view. So we have to be very careful with reading rows from InnoDB.
