Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-29299

SELECT from table with vcol index reports warning

Details

    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

          Activity

            nikitamalyavin Nikita Malyavin created issue -
            nikitamalyavin Nikita Malyavin made changes -
            Field Original Value New Value
            nikitamalyavin Nikita Malyavin made changes -
            Labels affects-tests
            nikitamalyavin Nikita Malyavin made changes -
            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
            nikitamalyavin Nikita Malyavin made changes -
            Assignee Thirunarayanan Balathandayuthapani [ thiru ] Nikita Malyavin [ nikitamalyavin ]
            marko Marko Mäkelä made changes -
            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 ]
            nikitamalyavin Nikita Malyavin added a comment - - edited

            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.

            nikitamalyavin Nikita Malyavin added a comment - - edited 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.
            nikitamalyavin Nikita Malyavin made changes -
            Status Open [ 1 ] In Progress [ 3 ]
            nikitamalyavin Nikita Malyavin added a comment - - edited

            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

            nikitamalyavin Nikita Malyavin added a comment - - edited 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

            nikitamalyavin Nikita Malyavin added a comment - serg please review together with MDEV-29181 , branch bb-10.5-nikita
            nikitamalyavin Nikita Malyavin made changes -
            Assignee Nikita Malyavin [ nikitamalyavin ] Sergei Golubchik [ serg ]
            Status In Progress [ 3 ] In Review [ 10002 ]

            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.

            serg Sergei Golubchik added a comment - 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.
            serg Sergei Golubchik made changes -
            Assignee Sergei Golubchik [ serg ] Nikita Malyavin [ nikitamalyavin ]
            Status In Review [ 10002 ] Stalled [ 10000 ]

            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 Sergei Golubchik added a comment - 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.

            SELECT * FROM t;

            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.

            nikitamalyavin Nikita Malyavin added a comment - serg , 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 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().

            serg Sergei Golubchik added a comment - That's why I suggest to use Dummy_error_handler in innobase_get_computed_value() .
            nikitamalyavin Nikita Malyavin made changes -
            Status Stalled [ 10000 ] In Progress [ 3 ]
            nikitamalyavin Nikita Malyavin made changes -
            Assignee Nikita Malyavin [ nikitamalyavin ] Marko Mäkelä [ marko ]
            Status In Progress [ 3 ] In Review [ 10002 ]
            nikitamalyavin Nikita Malyavin made changes -
            Assignee Marko Mäkelä [ marko ] Nikita Malyavin [ nikitamalyavin ]
            nikitamalyavin Nikita Malyavin made changes -
            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]\ ]
            nikitamalyavin Nikita Malyavin made changes -
            Status In Review [ 10002 ] Stalled [ 10000 ]
            nikitamalyavin Nikita Malyavin made changes -
            Status Stalled [ 10000 ] In Progress [ 3 ]
            nikitamalyavin Nikita Malyavin made changes -

            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 Marko Mäkelä added a comment - 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

            nikitamalyavin Nikita Malyavin added a comment - 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
            nikitamalyavin Nikita Malyavin made changes -
            Assignee Nikita Malyavin [ nikitamalyavin ] Marko Mäkelä [ marko ]
            Status In Progress [ 3 ] In Review [ 10002 ]

            Thank you, nikitamalyavin, both changes look correct to me. I posted some style suggestions that I hope you will address.

            marko Marko Mäkelä added a comment - Thank you, nikitamalyavin , both changes look correct to me. I posted some style suggestions that I hope you will address.
            marko Marko Mäkelä made changes -
            Assignee Marko Mäkelä [ marko ] Nikita Malyavin [ nikitamalyavin ]
            Status In Review [ 10002 ] Stalled [ 10000 ]

            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

            nikitamalyavin Nikita Malyavin added a comment - 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
            nikitamalyavin Nikita Malyavin made changes -
            Assignee Nikita Malyavin [ nikitamalyavin ] Sergei Golubchik [ serg ]
            Status Stalled [ 10000 ] In Review [ 10002 ]

            ok to push, but squash 857d85 and e978c2 and "fix mrn" into one commit.

            serg Sergei Golubchik added a comment - ok to push, but squash 857d85 and e978c2 and "fix mrn" into one commit.
            serg Sergei Golubchik made changes -
            Assignee Sergei Golubchik [ serg ] Nikita Malyavin [ nikitamalyavin ]
            Status In Review [ 10002 ] Stalled [ 10000 ]
            serg Sergei Golubchik made changes -
            serg Sergei Golubchik made changes -
            nikitamalyavin Nikita Malyavin made changes -
            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 ]

            People

              nikitamalyavin Nikita Malyavin
              nikitamalyavin Nikita Malyavin
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.