Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.3.36, 10.10.1, 10.4(EOL), 10.5, 10.6, 10.7(EOL), 10.8(EOL), 10.9(EOL)
-
Ubuntu 20.04
Description
I used my fuzzing tool to test MariaDB and found a transaction-related bug that make the server produce different results.
Mariadb installation
1) cd mariadb-10.10.1
2) mkdir build; cd build
3) cmake .. -DCMAKE_BUILD_TYPE=Debug -DWITH_ASAN=ON
4) make -j12 && sudo make install
Setup the environment
1) /usr/local/mysql/bin/mysqld --basedir=/usr/local/mysql --datadir=/usr/local/mysql/data --plugin-dir=/usr/local/mysql/lib/plugin --user=mysql &
2) /usr/local/mysql/bin/mysql -uroot -Dtestdb < mysql_bk.sql # set up the database, mysql_bk.sql is attached.
Reproduce bug
/usr/local/mysql/bin/mysql -uroot -Dtestdb # set up for the transaction T0
/usr/local/mysql/bin/mysql -uroot -Dtestdb # set up for the transaction T1
T0> SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ;
T1> SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ;
T1> START TRANSACTION;
T1> update t_g6ckkb set wkey = 162;
T0> START TRANSACTION;
T0> select * from t_g6ckkb;
T1> COMMIT;
T0> select * from t_rpjlsd where t_rpjlsd.c_pfd8ab <= (select min(wkey) from t_g6ckkb);
+------+--------+----------+----------+----------+----------+----------+----------+---------+---------+
|
| wkey | pkey | c_trycnb | c_5b3h_c | c_pfd8ab | c_mvgo1c | c_2twe2d | c_nmcpzc | c_loj6e | c_veoe1 |
|
+------+--------+----------+----------+----------+----------+----------+----------+---------+---------+
|
| 43 | 243000 | 30 | NULL | 8 | NULL | 70 | NULL | awnrab | 39.83 | |
+------+--------+----------+----------+----------+----------+----------+----------+---------+---------+
|
1 rows in set (0.006 sec) |
T0> update t_rpjlsd set wkey = 63 where t_rpjlsd.c_pfd8ab <= (select min(wkey) from t_g6ckkb);
Query OK, 2 rows affected (0.003 sec) |
Rows matched: 2 Changed: 2 Warnings: 0 |
T0> select * from t_rpjlsd where wkey = 63;
+------+--------+----------+----------+----------+----------+----------+----------+---------+---------+
|
| wkey | pkey | c_trycnb | c_5b3h_c | c_pfd8ab | c_mvgo1c | c_2twe2d | c_nmcpzc | c_loj6e | c_veoe1 |
|
+------+--------+----------+----------+----------+----------+----------+----------+---------+---------+
|
| 63 | 243000 | 30 | NULL | 8 | NULL | 70 | NULL | awnrab | 39.83 | |
| 63 | 332000 | 68 | _pqr1c | 53 | 9g7bt | NULL | 75 | tb1ugc | 7.62 | |
+------+--------+----------+----------+----------+----------+----------+----------+---------+---------+
|
2 rows in set (0.002 sec) |
T0> COMMIT;
Analysis
The first SELECT in T0 and the UPDATE in T0 should handle the same rows because they use the same predicate (WHERE clause) and execute adjacently. However, the first SELECT in T0 outputs only 1 row while the UPDATE in T0 changes 2 rows. To make sure what the UPDATE in T0 changes, we use the second SELECT in T0, and it outputs the changed 2 rows.
Based on the analysis, I think it might be a bug triggering inconsistent read (first SELECT in T0) and write (UPDATE in T0).
Attachments
Issue Links
- relates to
-
-
- In Review
-
-
-
- Closed
-
Activity
Here is a simpler version of the test:
--source include/have_innodb.inc
|
|
|
CREATE TABLE t_g6ckkb (wkey int) ENGINE=InnoDB; |
INSERT INTO t_g6ckkb VALUES (20),(56); |
|
|
CREATE TABLE t_rpjlsd ( |
wkey int, |
pkey int PRIMARY KEY, |
c_pfd8ab int |
) ENGINE=InnoDB DEFAULT CHARSET=latin1; |
|
|
INSERT INTO t_rpjlsd VALUES (43,243000,8),(57,332000,53); |
|
|
--connect con1,localhost,root
|
SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ; |
START TRANSACTION; |
UPDATE t_g6ckkb SET wkey=53 LIMIT 1; |
|
|
--connection default
|
SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ; |
START TRANSACTION WITH CONSISTENT SNAPSHOT; |
|
|
--connection con1
|
COMMIT; |
--disconnect con1
|
--connection default
|
select * from t_g6ckkb; |
select * from t_rpjlsd where c_pfd8ab <= (select min(wkey) from t_g6ckkb); |
update t_rpjlsd set wkey = 63 where c_pfd8ab <= (select min(wkey) from t_g6ckkb); |
select * from t_rpjlsd; |
COMMIT; |
|
|
DROP TABLE t_rpjlsd,t_g6ckkb; |
I looked up another reported read view anomaly MDEV-26642, but that scenario is different. Here, the subquery executed during the UPDATE will use a locking read, which is essentially a combination of READ UNCOMMITTED and a lock. The locking read was enabled by the SQL layer:
|
10.6 5d9d379329abcbb661ed6c027efbb9fd763958c6 |
Thread 12 hit Hardware watchpoint 3: -location m_prebuilt.select_lock_type
|
|
|
Old value = LOCK_NONE
|
New value = LOCK_S
|
ha_innobase::store_lock (this=0x61d0002864b8, thd=<optimized out>, to=<optimized out>, lock_type=TL_READ) at /mariadb/10.6/storage/innobase/handler/ha_innodb.cc:16528
|
16528 m_prebuilt->stored_select_lock_type = LOCK_S;
|
(rr) print m_prebuilt.table.name
|
$6 = {m_name = 0x604000025668 "test/t_g6ckkb"}
|
(rr) backtrace
|
#0 ha_innobase::store_lock (this=0x61d0002864b8, thd=<optimized out>, to=<optimized out>, lock_type=TL_READ) at /mariadb/10.6/storage/innobase/handler/ha_innodb.cc:16528
|
#1 0x000056451f6c1550 in get_lock_data (thd=thd@entry=0x62b0000bd218, table_ptr=table_ptr@entry=0x62b0000c6a60, count=count@entry=2, flags=flags@entry=3) at /mariadb/10.6/sql/lock.cc:812
|
#2 0x000056451f6c1951 in mysql_lock_tables (thd=thd@entry=0x62b0000bd218, tables=tables@entry=0x62b0000c6a60, count=count@entry=2, flags=flags@entry=0) at /mariadb/10.6/sql/lock.cc:301
|
#3 0x000056451f77f156 in lock_tables (thd=thd@entry=0x62b0000bd218, tables=0x62b0000c43c0, count=<optimized out>, flags=flags@entry=0) at /mariadb/10.6/sql/sql_base.cc:5550
|
#4 0x000056451fc19b2a in mysql_update (thd=thd@entry=0x62b0000bd218, table_list=<optimized out>,
|
fields=@0x62b0000c2018: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x62b0000c4c90, last = 0x62b0000c4c90, elements = 1}, <No data fields>},
|
values=@0x62b0000c2440: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x62b0000c4ca8, last = 0x62b0000c4ca8, elements = 1}, <No data fields>}, conds=<optimized out>, order_num=<optimized out>,
|
order=<optimized out>, limit=<optimized out>, ignore=<optimized out>, found_return=<optimized out>, updated_return=<optimized out>) at /mariadb/10.6/sql/sql_update.cc:442
|
#5 0x000056451f987ab7 in mysql_execute_command (thd=thd@entry=0x62b0000bd218, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /mariadb/10.6/sql/sql_parse.cc:4408
|
#6 0x000056451f993713 in mysql_parse (thd=thd@entry=0x62b0000bd218, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f6198c61a00) at /mariadb/10.6/sql/sql_parse.cc:8030
|
#7 0x000056451f997ae4 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62b0000bd218,
|
packet=packet@entry=0x629000276219 "update t_rpjlsd set wkey = 63 where c_pfd8ab <= (select min(wkey) from t_g6ckkb)", packet_length=packet_length@entry=80, blocking=blocking@entry=true)
|
at /mariadb/10.6/sql/sql_parse.cc:1896
|
I am not sure what the correct fix should be. Like in MDEV-26642, a locking read has probably been used for the ‘read’ part since the beginning of MySQL, and some applications could break if this were changed. MDEV-24813 lists some other statements that should suffer from the same. These include INSERT…SELECT.
This is intentional and expected behavior. May be it's not sufficiently clear documented in KB, we need to correct that.
MySQL manual, though, clearly says
If a transaction does update or delete rows committed by a different transaction, those changes do become visible to the current transaction
This is an inherent part (or limitation?) of InnoDB design.
If I set innodb_snapshot_isolation=ON (introduced in the fix of MDEV-26642, MDEV-26643, MDEV-32898; see PR#3067), then my test case will fail instead of producing inconsistent results:
|
10.6 b8a671988954870b7db22e20d1a1409fd40f8e3d |
mysqltest: At line 29: query 'update t_rpjlsd set wkey = 63 where c_pfd8ab <= (select min(wkey) from t_g6ckkb)' failed: ER_CHECKREAD (1020): Record has changed since last read in table 't_g6ckkb'
|
confirmed on 10.3.37-beffef9f0019d4519447339564d2cf18bebb8401 too