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
-
-
- Stalled
-
- includes
-
-
- Closed
-
Activity
The most simplified test case doesn't need a patch for reproduction, nor the forein keys:
--source include/have_innodb.inc
|
--connect (con2, localhost, root,,)
|
--connection default
|
set default_storage_engine= innodb;
|
|
|
CREATE TABLE t(fld1 INT NOT NULL,
|
fld2 INT AS (100/fld1) VIRTUAL,
|
KEY(fld2));
|
CREATE TABLE t_odd(id int);
|
INSERT INTO t(fld1) VALUES(1), (2);
|
--connection con2
|
begin;
|
INSERT INTO t_odd VALUES(10000);
|
--connection default
|
UPDATE IGNORE t SET fld1= 0 WHERE fld1= 2;
|
SELECT fld2 FROM t;
|
|
|
--disconnect con2
|
DROP TABLE t, t_odd;
|
--connection default
|
nor debug_sync, which makes it possible to be run on non-debug configs
serg please review together with MDEV-29181, branch bb-10.5-nikita
Why is it a bug? Recalculating vcols on SELECT is quite normal, if you do, e.g.
SELECT * FROM t; |
then vcol will definitely be recalculated, and it's expected. With keyread it's generally not recalculated indeed, but a keyread is an optimization and it's up to the optimizer to decide whether to use it or not. There can be many factors that affect if there will be a need to recalculate a vcol or not and it appears you've found yet another one. I don't think it needs fixing though.
On the other hand, modifying your test case as
...
|
UPDATE IGNORE t SET fld1= 3 WHERE fld1= 2; |
UPDATE IGNORE t SET fld1= 4 WHERE fld1= 3; |
UPDATE IGNORE t SET fld1= 0 WHERE fld1= 4; |
SELECT fld2 FROM t; |
I got four warnings for one row. This is clearly unexpected. But then he fix should be inside InnoDB, suppressing warnings (and errors) when evaluating vcols for deleted values. For example, with an extra argument to innobase_get_computed_value() like bool suppress_warnings. It can use Dummy_error_handler, as evaluating vcols for deleted values should be totally invisible and free of side effects.
serg,
Why is it a bug? Recalculating vcols on SELECT is quite normal, if you do, e.g.
then vcol will definitely be recalculated, and it's expected
But the user can be aware of the execution plan, and given that, they can tell whether the column will be recalculated or not.
Here, this execution may look completely random, as even access to the tables the user may be unaware of may cause this.
For example, with an extra argument to innobase_get_computed_value() like bool suppress_warnings
I was thinking about it first, too, but then came across simpler and more general solution
as evaluating vcols for deleted values should be totally invisible and free of side effects.
evauating vcols on mvcc purposes should be also free of side-effects. And it is implementation-defined, it can be gone after implementing MDEV-17598.
Though, serg if you still think it is the correct behavior to output the warning after the points above, I'd rather fix the test as marko suggested, by opting out consistent statistics for the table, and would report a separate bug for suppressing delete-marked rows evaluation warnings, not blocking MDEV-29181.
That's why I suggest to use Dummy_error_handler in innobase_get_computed_value().
nikitamalyavin, the commit message is giving an incomplete description of multi-versioning in secondary indexes:
When the page is fetched, its max_trx_id is compared to m_up_limit_id. If the value is lower, then this page is just safe to read as is.
This is missing an important part and the secondary index record is not delete-marked.
marko please review commit b9fa4149 [github].
As it turned out in MDEV-29753, suppressing the warnings for SELECTs only is not enough.
So adding a parameter to innobase_get_computed_value is reasonable.
I also couldn't avoid modfying {{sql_class.cc }}, because THD contents are not directly accessible from innodb, so serg's review will also be required.
You can also review MDEV-29753 solution (b212f4021, github) in one scope, since they are co-related
Thank you, nikitamalyavin, both changes look correct to me. I posted some style suggestions that I hope you will address.
I have updated the patches with accordance to marko's notes, and also have changed the base to 10.3
serg please now review commits 857d85 and MDEV-29753 patch e978c2
ok to push, but squash 857d85 and e978c2 and "fix mrn" into one commit.
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:10CURRENT_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 @@fld2NULL100+Warnings:+Warning 1365 Division by 0DROP TABLE t2, t1;# CHANGE SQL_MODE and try the ERROR_FOR_DIVISION_BY_ZEROSET 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:53795379 goto requires_clust_rec;(gdb) l5374 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 }53815382 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 = 33Previously, 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:12271227 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.