Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
None
Description
With the following patch applied,
diff --git a/sql/sql_insert.cc b/sql/sql_insert.cc
|
--- a/sql/sql_insert.cc
|
+++ b/sql/sql_insert.cc
|
@@ -1132,6 +1132,8 @@
|
error= write_record(thd, table, &info, result);
|
if (unlikely(error))
|
break;
|
+
|
+ DEBUG_SYNC(thd, "after_write_record");
|
info.accepted_rows++;
|
}
|
its.rewind(); |
the following test outputs warning in SELECT:
# Run with --innodb-page-size=4K |
|
--source include/have_debug_sync.inc
|
--source include/have_innodb.inc
|
--source include/have_sequence.inc
|
--connect (con2, localhost, root,,)
|
--connection default
|
set default_storage_engine= innodb; |
|
CREATE TABLE t1(fld1 INT NOT NULL PRIMARY KEY); |
CREATE TABLE t2(fld1 INT NOT NULL, |
fld2 INT AS (100/fld1) VIRTUAL, |
KEY(fld2), |
FOREIGN KEY(fld1) REFERENCES t1(fld1) |
ON UPDATE CASCADE); |
INSERT INTO t1 SELECT * from seq_1_to_1025; # Fill enough to make a new block |
INSERT INTO t2 VALUES(1, DEFAULT), (2, default); |
--connection con2
|
set debug_sync = "after_write_record signal go wait_for finish"; |
send INSERT INTO t1 VALUES(10000); |
--connection default
|
#--error ER_DIVISION_BY_ZERO |
set debug_sync = "now wait_for go"; |
UPDATE IGNORE t1 SET fld1= 0 WHERE fld1= 2; |
SELECT fld2 FROM t2; |
|
set debug_sync = "now signal finish"; |
DROP TABLE t2, t1; |
|
set debug_sync= reset; |
--connection default |
This affects gcol.innodb_virtual_fk making it nondeterministically output ER_DIVISION_BY_ZERO warning
Attachments
Issue Links
- blocks
-
MDEV-29181 Potential corruption on Foreign key update on a table with vcol index
-
- Stalled
-
- includes
-
MDEV-29753 An error is wrongly reported during INSERT with vcol index
-
- Closed
-
Activity
Field | Original Value | New Value |
---|---|---|
Link | This issue blocks MDEV-29181 [ MDEV-29181 ] |
Labels | affects-tests |
Description |
With the following patch applied,
{code:diff} diff --git a/sql/sql_insert.cc b/sql/sql_insert.cc --- a/sql/sql_insert.cc +++ b/sql/sql_insert.cc @@ -1132,6 +1132,8 @@ error= write_record(thd, table, &info, result); if (unlikely(error)) break; + + DEBUG_SYNC(thd, "after_write_record"); info.accepted_rows++; } its.rewind(); {code} the following test outputs warning in SELECT: {code:sql} # Run with --innodb-page-size=4K --source include/have_debug_sync.inc --source include/have_innodb.inc --source include/have_sequence.inc --connect (con2, localhost, root,,) --connection default set default_storage_engine= innodb; CREATE TABLE t1(fld1 INT NOT NULL PRIMARY KEY); CREATE TABLE t2(fld1 INT NOT NULL, fld2 INT AS (100/fld1) VIRTUAL, KEY(fld2), FOREIGN KEY(fld1) REFERENCES t1(fld1) ON UPDATE CASCADE); INSERT INTO t1 SELECT * from seq_1_to_1025; # Fill enough to make a new block INSERT INTO t2 VALUES(1, DEFAULT), (2, default); --connection con2 set debug_sync = "after_write_record signal go wait_for finish"; send INSERT INTO t1 VALUES(10000); --connection default #--error ER_DIVISION_BY_ZERO set debug_sync = "now wait_for go"; UPDATE IGNORE t1 SET fld1= 0 WHERE fld1= 2; SELECT fld2 FROM t2; set debug_sync = "now signal finish"; DROP TABLE t2, t1; set debug_sync= reset; --connection default {code} |
With the following patch applied,
{code:diff} diff --git a/sql/sql_insert.cc b/sql/sql_insert.cc --- a/sql/sql_insert.cc +++ b/sql/sql_insert.cc @@ -1132,6 +1132,8 @@ error= write_record(thd, table, &info, result); if (unlikely(error)) break; + + DEBUG_SYNC(thd, "after_write_record"); info.accepted_rows++; } its.rewind(); {code} the following test outputs warning in SELECT: {code:sql} # Run with --innodb-page-size=4K --source include/have_debug_sync.inc --source include/have_innodb.inc --source include/have_sequence.inc --connect (con2, localhost, root,,) --connection default set default_storage_engine= innodb; CREATE TABLE t1(fld1 INT NOT NULL PRIMARY KEY); CREATE TABLE t2(fld1 INT NOT NULL, fld2 INT AS (100/fld1) VIRTUAL, KEY(fld2), FOREIGN KEY(fld1) REFERENCES t1(fld1) ON UPDATE CASCADE); INSERT INTO t1 SELECT * from seq_1_to_1025; # Fill enough to make a new block INSERT INTO t2 VALUES(1, DEFAULT), (2, default); --connection con2 set debug_sync = "after_write_record signal go wait_for finish"; send INSERT INTO t1 VALUES(10000); --connection default #--error ER_DIVISION_BY_ZERO set debug_sync = "now wait_for go"; UPDATE IGNORE t1 SET fld1= 0 WHERE fld1= 2; SELECT fld2 FROM t2; set debug_sync = "now signal finish"; DROP TABLE t2, t1; set debug_sync= reset; --connection default {code} This affects {{gcol.innodb_virtual_fk}} making it nondeterministically output ER_DIVISION_BY_ZERO warning |
Assignee | Thirunarayanan Balathandayuthapani [ thiru ] | Nikita Malyavin [ nikitamalyavin ] |
Component/s | Storage Engine - InnoDB [ 10129 ] | |
Component/s | Virtual Columns [ 10803 ] | |
Fix Version/s | 10.3 [ 22126 ] | |
Fix Version/s | 10.4 [ 22408 ] | |
Fix Version/s | 10.5 [ 23123 ] | |
Fix Version/s | 10.6 [ 24028 ] | |
Fix Version/s | 10.7 [ 24805 ] | |
Fix Version/s | 10.8 [ 26121 ] | |
Fix Version/s | 10.9 [ 26905 ] | |
Fix Version/s | 10.10 [ 27530 ] |
Status | Open [ 1 ] | In Progress [ 3 ] |
Assignee | Nikita Malyavin [ nikitamalyavin ] | Sergei Golubchik [ serg ] |
Status | In Progress [ 3 ] | In Review [ 10002 ] |
Assignee | Sergei Golubchik [ serg ] | Nikita Malyavin [ nikitamalyavin ] |
Status | In Review [ 10002 ] | Stalled [ 10000 ] |
Status | Stalled [ 10000 ] | In Progress [ 3 ] |
Assignee | Nikita Malyavin [ nikitamalyavin ] | Marko Mäkelä [ marko ] |
Status | In Progress [ 3 ] | In Review [ 10002 ] |
Assignee | Marko Mäkelä [ marko ] | Nikita Malyavin [ nikitamalyavin ] |
Comment |
[ ~marko] I have changed my patch according to serg's suggestion.
But now it's on your responsibility side. Please review commit {{099dbca7}} \[[github|https://github.com/MariaDB/server/commit/099dbca7377f96b3f181154a8c9fb197a7820490]\ ] |
Status | In Review [ 10002 ] | Stalled [ 10000 ] |
Status | Stalled [ 10000 ] | In Progress [ 3 ] |
Link |
This issue relates to |
Assignee | Nikita Malyavin [ nikitamalyavin ] | Marko Mäkelä [ marko ] |
Status | In Progress [ 3 ] | In Review [ 10002 ] |
Assignee | Marko Mäkelä [ marko ] | Nikita Malyavin [ nikitamalyavin ] |
Status | In Review [ 10002 ] | Stalled [ 10000 ] |
Assignee | Nikita Malyavin [ nikitamalyavin ] | Sergei Golubchik [ serg ] |
Status | Stalled [ 10000 ] | In Review [ 10002 ] |
Assignee | Sergei Golubchik [ serg ] | Nikita Malyavin [ nikitamalyavin ] |
Status | In Review [ 10002 ] | Stalled [ 10000 ] |
Link |
This issue includes |
Link |
This issue relates to |
Fix Version/s | 10.3.37 [ 28404 ] | |
Fix Version/s | 10.4.27 [ 28405 ] | |
Fix Version/s | 10.5.18 [ 28421 ] | |
Fix Version/s | 10.6.11 [ 28441 ] | |
Fix Version/s | 10.7.7 [ 28442 ] | |
Fix Version/s | 10.8.6 [ 28443 ] | |
Fix Version/s | 10.9.4 [ 28444 ] | |
Fix Version/s | 10.10.2 [ 28410 ] | |
Fix Version/s | 10.3 [ 22126 ] | |
Fix Version/s | 10.4 [ 22408 ] | |
Fix Version/s | 10.5 [ 23123 ] | |
Fix Version/s | 10.6 [ 24028 ] | |
Fix Version/s | 10.7 [ 24805 ] | |
Fix Version/s | 10.8 [ 26121 ] | |
Fix Version/s | 10.9 [ 26905 ] | |
Fix Version/s | 10.10 [ 27530 ] | |
Resolution | Fixed [ 1 ] | |
Status | Stalled [ 10000 ] | Closed [ 6 ] |
I have found this oddity when I was testing my new MDEV-29181 solution (commit, branch bb-10.10-MDEV-29181), where gcol.innodb_virtual_fk began failing:
gcol.innodb_virtual_fk 'innodb' [ fail ]
Test ended at 2022-08-12 01:06:10
CURRENT_TEST: gcol.innodb_virtual_fk
--- /home/nik/mariadb/mysql-test/suite/gcol/r/innodb_virtual_fk.result 2022-06-27 20:45:05.117537870 +0300
+++ /home/nik/mariadb/mysql-test/suite/gcol/r/innodb_virtual_fk.reject 2022-08-12 01:06:09.755770884 +0300
@@ -352,6 +352,8 @@
fld2
NULL
100
+Warnings:
+Warning 1365 Division by 0
DROP TABLE t2, t1;
# CHANGE SQL_MODE and try the ERROR_FOR_DIVISION_BY_ZERO
SET sql_mode = STRICT_ALL_TABLES;
It's likely not my bug (proven by test in a description), but something in cascade updates shifted in its evaluation speed (became faster i believe
), and some table stats didn't didn't finish its update before SELECT's read view opens.
Therefore I've seen that row_search_mvcc considers a fetched page as something like requiring check, and falls into goto requires_clust_rec.
Thread 2 hit Breakpoint 11, row_search_mvcc (buf=0x6190000e0bc8 "\377", mode=PAGE_CUR_G, prebuilt=0x620000025108, match_mode=0, direction=0) at /home/nik/mariadb/storage/innobase/row/row0sel.cc:5379
5379 goto requires_clust_rec;
(gdb) l
5374 case CHECK_OUT_OF_RANGE:
5375 case CHECK_ERROR:
5376 err = DB_RECORD_NOT_FOUND;
5377 goto idx_cond_failed;
5378 case CHECK_POS:
5379 goto requires_clust_rec;
5380 }
5381
5382 ut_error;
5383 }
(gdb) bt
#0 row_search_mvcc (buf=0x6190000e0bc8 "\377", mode=PAGE_CUR_G, prebuilt=0x620000025108, match_mode=0, direction=0) at /home/nik/mariadb/storage/innobase/row/row0sel.cc:5379
#1 0x00005559b25c7f90 in ha_innobase::index_read (this=0x61d0003192b8, buf=0x6190000e0bc8 "\377", key_ptr=0x0, key_len=0, find_flag=HA_READ_AFTER_KEY) at /home/nik/mariadb/storage/innobase/handler/ha_innodb.cc:8996
#2 0x00005559b25ca0ad in ha_innobase::index_first (this=0x61d0003192b8, buf=0x6190000e0bc8 "\377") at /home/nik/mariadb/storage/innobase/handler/ha_innodb.cc:9351
#3 0x00005559b0d0abce in handler::ha_index_first (this=0x61d0003192b8, buf=0x6190000e0bc8 "\377") at /home/nik/mariadb/sql/handler.cc:3566
#4 0x00005559b195854f in join_read_first (tab=0x62900004dc30) at /home/nik/mariadb/sql/sql_select.cc:22315
#5 0x00005559b183ed77 in sub_select (join=0x62900004c930, join_tab=0x62900004dc30, end_of_records=false) at /home/nik/mariadb/sql/sql_select.cc:21275
#6 0x00005559b18c7b0b in do_select (join=0x62900004c930, procedure=0x0) at /home/nik/mariadb/sql/sql_select.cc:20823
#7 0x00005559b18c4209 in JOIN::exec_inner (this=0x62900004c930) at /home/nik/mariadb/sql/sql_select.cc:4787
#8 0x00005559b18c0933 in JOIN::exec (this=0x62900004c930) at /home/nik/mariadb/sql/sql_select.cc:4565
#9 0x00005559b184157a in mysql_select (thd=0x62b00015e218, tables=0x62900004b8f0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x62900004c900, unit=0x62b000162440, select_lex=0x62900004b2d0) at /home/nik/mariadb/sql/sql_select.cc:5045
#10 0x00005559b18401b2 in handle_select (thd=0x62b00015e218, lex=0x62b000162368, result=0x62900004c900, setup_tables_done_option=0) at /home/nik/mariadb/sql/sql_select.cc:579
#11 0x00005559b17176da in execute_sqlcom_select (thd=0x62b00015e218, all_tables=0x62900004b8f0) at /home/nik/mariadb/sql/sql_parse.cc:6260
#12 0x00005559b16facb5 in mysql_execute_command (thd=0x62b00015e218, is_called_from_prepared_stmt=false) at /home/nik/mariadb/sql/sql_parse.cc:3944
#13 0x00005559b16e3045 in mysql_parse (thd=0x62b00015e218, rawbuf=0x62900004b238 "SELECT fld2 FROM t2", length=19, parser_state=0x7f005cea0ab0) at /home/nik/mariadb/sql/sql_parse.cc:8036
#14 0x00005559b16dbcdf in dispatch_command (command=COM_QUERY, thd=0x62b00015e218, packet=0x629000271219 "", packet_length=19, blocking=true) at /home/nik/mariadb/sql/sql_parse.cc:1894
#15 0x00005559b16e589f in do_command (thd=0x62b00015e218, blocking=true) at /home/nik/mariadb/sql/sql_parse.cc:1407
#16 0x00005559b1d27826 in do_handle_one_connection (connect=0x608000002b38, put_in_cache=true) at /home/nik/mariadb/sql/sql_connect.cc:1418
#17 0x00005559b1d26ef7 in handle_one_connection (arg=0x608000002ab8) at /home/nik/mariadb/sql/sql_connect.cc:1312
#18 0x00007f0066f3e54d in ?? () from target:/usr/lib/libc.so.6
#19 0x00007f0066fc3874 in clone () from target:/usr/lib/libc.so.6
(gdb) p trx->read_view.m_up_limit_id
$1 = 33
Previously, the transaction with id 33 was registered on background dict_stats_update call
Thread 8 "mariadbd" hit Breakpoint 7, trx_sys_t::get_new_trx_id_no_refresh (this=0x55555aa318c0 <trx_sys>) at /home/nik/mariadb/storage/innobase/include/trx0sys.h:1227
1227 return m_max_trx_id++;
(gdb) bt
#0 trx_sys_t::get_new_trx_id_no_refresh (this=0x55555aa318c0 <trx_sys>) at /home/nik/mariadb/storage/innobase/include/trx0sys.h:1227
#1 0x0000555559c13b2d in trx_sys_t::register_rw (this=0x55555aa318c0 <trx_sys>, trx=0x7ffff3eeee40) at /home/nik/mariadb/storage/innobase/include/trx0sys.h:1091
#2 0x0000555559c0a6a0 in trx_start_low (trx=0x7ffff3eeee40, read_write=true) at /home/nik/mariadb/storage/innobase/trx/trx0trx.cc:962
#3 0x0000555559c0f1cb in trx_start_internal_low (trx=0x7ffff3eeee40, read_write=true) at /home/nik/mariadb/storage/innobase/trx/trx0trx.cc:2123
#4 0x00005555595f2088 in dict_stats_save (table_orig=0x618000030d08, only_for_index=0x0) at /home/nik/mariadb/storage/innobase/dict/dict0stats.cc:3078
#5 0x00005555595f4863 in dict_stats_update (table=0x618000030d08, stats_upd_option=DICT_STATS_RECALC_PERSISTENT) at /home/nik/mariadb/storage/innobase/dict/dict0stats.cc:3878
#6 0x00005555595dfcfa in dict_stats_process_entry_from_recalc_pool (thd=0x62b00018f218) at /home/nik/mariadb/storage/innobase/dict/dict0stats_bg.cc:344
#7 0x00005555595dd4be in dict_stats_func () at /home/nik/mariadb/storage/innobase/dict/dict0stats_bg.cc:382
#8 0x0000555559c52f65 in tpool::thread_pool_generic::timer_generic::run (this=0x612000002bc0) at /home/nik/mariadb/tpool/tpool_generic.cc:352
#9 0x0000555559c52bcd in tpool::thread_pool_generic::timer_generic::execute (arg=0x612000002bc0) at /home/nik/mariadb/tpool/tpool_generic.cc:371
#10 0x0000555559c62b93 in tpool::task::execute (this=0x612000002c00) at /home/nik/mariadb/tpool/task.cc:37
#11 0x0000555559c494b8 in tpool::thread_pool_generic::worker_main (this=0x618000000c80, thread_var=0x63000001fc00) at /home/nik/mariadb/tpool/tpool_generic.cc:588
#12 0x0000555559c5a687 in std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__f=@0x604000006028: (void (tpool::thread_pool_generic::*)(tpool::thread_pool_generic * const, tpool::worker_data *)) 0x555559c49260 <tpool::thread_pool_generic::worker_main(tpool::worker_data*)>, __t=@0x604000006020: 0x618000000c80, __args=@0x604000006018: 0x63000001fc00) at /usr/bin/../lib64/gcc/x86_64-pc-linux-gnu/12.1.0/../../../../include/c++/12.1.0/bits/invoke.h:74
#13 0x0000555559c5a4c7 in std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__fn=@0x604000006028: (void (tpool::thread_pool_generic::*)(tpool::thread_pool_generic * const, tpool::worker_data *)) 0x555559c49260 <tpool::thread_pool_generic::worker_main(tpool::worker_data*)>, __args=@0x604000006018: 0x63000001fc00, __args=@0x604000006018: 0x63000001fc00) at /usr/bin/../lib64/gcc/x86_64-pc-linux-gnu/12.1.0/../../../../include/c++/12.1.0/bits/invoke.h:96
#14 0x0000555559c5a46b in std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::_M_invoke<0ul, 1ul, 2ul> (this=0x604000006018) at /usr/bin/../lib64/gcc/x86_64-pc-linux-gnu/12.1.0/../../../../include/c++/12.1.0/bits/std_thread.h:252
#15 0x0000555559c5a405 in std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator() (this=0x604000006018) at /usr/bin/../lib64/gcc/x86_64-pc-linux-gnu/12.1.0/../../../../include/c++/12.1.0/bits/std_thread.h:259
#16 0x0000555559c5a139 in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> > >::_M_run (this=0x604000006010) at /usr/bin/../lib64/gcc/x86_64-pc-linux-gnu/12.1.0/../../../../include/c++/12.1.0/bits/std_thread.h:210
#17 0x00007ffff773d183 in std::execute_native_thread_routine (__p=0x604000006010) at /usr/src/debug/gcc/libstdc++-v3/src/c++11/thread.cc:82
#18 0x00007ffff74c554d in ?? () from /usr/lib/libc.so.6
#19 0x00007ffff754a874 in clone () from /usr/lib/libc.so.6
(gdb) p m_max_trx_id
$1 = {m_counter = {<std::__atomic_base<unsigned long>> = {static _S_alignment = 8, _M_i = 33}, <No data fields>}}
The active index is chosen to fld2 as it is the only one. The clustered index could not be chosen with ha_index_read if it wasn't declared.