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

gcol.gcol_purge causes innodb.gap_lock test failure

Details

    Description

      The failure can be reproduced with the following command:

      ./mtr --no-reorder gcol.gcol_purge innodb.gap_locks
      

      The result is the following:

      [Revision hash: b52b7b41296fa8857bcd2abc42f9ab6721b86f8b]
       
      innodb.gap_locks 'innodb'                w20 [ fail ]
              Test ended at 2023-11-06 15:06:15
       
      CURRENT_TEST: innodb.gap_locks
      --- /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/suite/innodb/r/gap_locks.result	2023-11-06 14:50:37.000000000 +0000
      +++ /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/suite/innodb/r/gap_locks.reject	2023-11-06 15:06:14.843197996 +0000
      @@ -8,28 +8,28 @@
       DELETE FROM t1 WHERE b='2' AND c=2;
       SHOW ENGINE INNODB STATUS;
       Type	Name	Status
      -InnoDB		2 lock struct(s), 1 row lock(s)
      +InnoDB		0 lock struct(s), 0 row lock(s)
       ROLLBACK;
       SET TRANSACTION ISOLATION LEVEL REPEATABLE READ;
       BEGIN;
       DELETE FROM t1 WHERE b='2' AND c=2;
       SHOW ENGINE INNODB STATUS;
       Type	Name	Status
      -InnoDB		2 lock struct(s), 1 row lock(s)
      +InnoDB		0 lock struct(s), 0 row lock(s)
       ROLLBACK;
       SET TRANSACTION ISOLATION LEVEL READ COMMITTED;
       BEGIN;
       DELETE FROM t1 WHERE b='2' AND c=2;
       SHOW ENGINE INNODB STATUS;
       Type	Name	Status
      -InnoDB		1 lock struct(s), 0 row lock(s)
      +InnoDB		0 lock struct(s), 0 row lock(s)
       ROLLBACK;
       SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED;
       BEGIN;
       DELETE FROM t1 WHERE b='2' AND c=2;
       SHOW ENGINE INNODB STATUS;
       Type	Name	Status
      -InnoDB		1 lock struct(s), 0 row lock(s)
      +InnoDB		0 lock struct(s), 0 row lock(s)
       ROLLBACK;
       SET GLOBAL INNODB_STATUS_OUTPUT_LOCKS = @save_locks;
       DROP TABLE t1;
       
      mysqltest: Result content mismatch
      
      

      Attachments

        Issue Links

          Activity

            vlad.lesin Vladislav Lesin added a comment - - edited

            The test fails after after gcol.gcol_purge. The gcol.gcol_purge registers trx with the following stack:

            #3  0x0000562476398b08 in trx_sys_t::register_trx (this=0x56247703b300 <trx_sys>, trx=0x7f8e38ccac80)
                at ./10.6/storage/innobase/include/trx0sys.h:1154                           
            #4  0x000056247638ef10 in trx_create () at ./10.6/storage/innobase/trx/trx0trx.cc:360
            #5  0x00005624760fedd0 in innobase_trx_allocate (thd=0x5624782af6d8) at ./10.6/storage/innobase/handler/ha_innodb.cc:2900
            #6  0x00005624760feeb8 in check_trx_exists (thd=0x5624782af6d8) at ./10.6/storage/innobase/handler/ha_innodb.cc:2925
            #7  0x00005624761202f7 in ha_innobase::extra (this=0x7f8e0c00d2a0, operation=HA_EXTRA_IS_ATTACHED_CHILDREN)
                at ./10.6/storage/innobase/handler/ha_innodb.cc:15740                       
            #8  0x0000562475c6646b in tc_acquire_table (thd=0x5624782af6d8, element=0x7f8e0c0bb9d8) at ./10.6/sql/table_cache.cc:411
            #9  0x0000562475c681e2 in tdc_acquire_share (thd=0x5624782af6d8, tl=0x7f8e28002590, flags=1, out_table=0x7f8e329f1338)
                at ./10.6/sql/table_cache.cc:883                                            
            #10 0x00005624758d758a in open_table (thd=0x5624782af6d8, table_list=0x7f8e28002590, ot_ctx=0x7f8e329f1620)
                at ./10.6/sql/sql_base.cc:1901                                              
            #11 0x0000562475911225 in open_purge_table (thd=0x5624782af6d8, db=0x7f8e329f16b0 "test", dblen=4, tb=0x7f8e329f1780 "t1", tblen=2)
                at ./10.6/sql/sql_class.cc:4968                                             
            #12 0x0000562476126b86 in innodb_find_table_for_vc (thd=0x5624782af6d8, table=0x7f8e0c039920)
                at ./10.6/storage/innobase/handler/ha_innodb.cc:20051                       
            #13 0x0000562476126e33 in innobase_allocate_row_for_vcol (thd=0x5624782af6d8, index=0x7f8e0c00caf0, heap=0x7f8e329f1980, table=0x7f8e329f1928,
                storage=0x7f8e329f1960) at ./10.6/storage/innobase/handler/ha_innodb.cc:20124
            #14 0x00005624762c16b0 in ib_vcol_row::record (this=0x7f8e329f1960, thd=0x5624782af6d8, index=0x7f8e0c00caf0, table=0x7f8e329f1928)
                at ./10.6/storage/innobase/include/row0mysql.h:763                          
            #15 0x0000562476344720 in row_vers_build_clust_v_col (row=0x7f8e28002100, clust_index=0x7f8e0c18cdc0, index=0x7f8e0c00caf0, heap=0x7f8e28002060)
                at ./10.6/storage/innobase/row/row0vers.cc:466                              
            #16 0x0000562476345d90 in row_vers_old_has_index_entry (also_curr=true, rec=0x7f8e3893407d "\200", mtr=0x7f8e329f1ac0, index=0x7f8e0c00caf0,
                ientry=0x7f8e280016d0, roll_ptr=844424950251792, trx_id=18) at ./10.6/storage/innobase/row/row0vers.cc:971
            #17 0x0000562476302186 in row_purge_poss_sec (node=0x56247817ac48, index=0x7f8e0c00caf0, entry=0x7f8e280016d0, sec_pcur=0x7f8e329f1ec0,
                sec_mtr=0x7f8e329f2140, is_tree=false) at ./10.6/storage/innobase/row/row0purge.cc:316
            #18 0x000056247630298b in row_purge_remove_sec_if_poss_leaf (node=0x56247817ac48, index=0x7f8e0c00caf0, entry=0x7f8e280016d0)
                at ./10.6/storage/innobase/row/row0purge.cc:481                             
            #19 0x0000562476302e1d in row_purge_remove_sec_if_poss (node=0x56247817ac48, index=0x7f8e0c00caf0, entry=0x7f8e280016d0)
                at ./10.6/storage/innobase/row/row0purge.cc:575                             
            #20 0x0000562476302f53 in row_purge_del_mark (node=0x56247817ac48) at ./10.6/storage/innobase/row/row0purge.cc:621
            #21 0x0000562476305120 in row_purge_record_func (node=0x56247817ac48, undo_rec=0x7f8e384c8110 "\001?\016", thr=0x56247817aba8, updated_extern=false)
                at ./10.6/storage/innobase/row/row0purge.cc:1125                            
            #22 0x00005624763053d0 in row_purge (node=0x56247817ac48, undo_rec=0x7f8e384c8110 "\001?\016", thr=0x56247817aba8)
                at ./10.6/storage/innobase/row/row0purge.cc:1186     
            

            check_trx_exists() creates new trx_t object if THD does not contain it. This object will never be freed and deregistered, because at one hand ha_innobase::extra() does not process HA_EXTRA_IS_ATTACHED_CHILDREN, and at the other hand purge_worker_callback() just invokes release_thd(), which does not free thd's trx_t object.

            So, after gcol.gcol_purge test execution trx_sys.trx_list contains the transaction, created with the above stack trace. "SHOW ENGINE INNODB STATUS" from innodb.gap_lock iterates trx_sys.trx_list from the beginning. In innodb.gap_lock "CREATE TABLE" creates trx_t object with trx_create(), pushes it in front of trx_sys_t::trx_list and assigns it to the connection's THD(the trx_t object is supposed to be deregistered, i.e. removed from trx_sys.trx_list, on disconnection, when the THD is deinitialized). So, when "SHOW ENGINE INNODB STATUS" is executed, trx_sys_t::trx_list contains two trx_t objects in the following order: created with "CREATE TABLE" in innodb.gap_lock, created with the above stack trace in gcol.gcol_purge. The latter transaction does not hold any locks. And this is the order in which "SHOW ENGINE INNODB STATUS" outputs information about the transactions.

            Regular expression

            --replace_regex /.*(\d+ lock struct...), heap size \d+(, \d+ row lock...).*/\1\2/
            

            in innodb.gap_lock is greedy, and shows only the last transaction info in the list, and, as the last transaction does not hold any locks, the test fails.

            As a fix I would propose not to invoke check_trx_exists() from ha_innobase::extra() if operation is ignored.

            vlad.lesin Vladislav Lesin added a comment - - edited The test fails after after gcol.gcol_purge. The gcol.gcol_purge registers trx with the following stack: #3 0x0000562476398b08 in trx_sys_t::register_trx (this=0x56247703b300 <trx_sys>, trx=0x7f8e38ccac80) at ./10.6/storage/innobase/include/trx0sys.h:1154 #4 0x000056247638ef10 in trx_create () at ./10.6/storage/innobase/trx/trx0trx.cc:360 #5 0x00005624760fedd0 in innobase_trx_allocate (thd=0x5624782af6d8) at ./10.6/storage/innobase/handler/ha_innodb.cc:2900 #6 0x00005624760feeb8 in check_trx_exists (thd=0x5624782af6d8) at ./10.6/storage/innobase/handler/ha_innodb.cc:2925 #7 0x00005624761202f7 in ha_innobase::extra (this=0x7f8e0c00d2a0, operation=HA_EXTRA_IS_ATTACHED_CHILDREN) at ./10.6/storage/innobase/handler/ha_innodb.cc:15740 #8 0x0000562475c6646b in tc_acquire_table (thd=0x5624782af6d8, element=0x7f8e0c0bb9d8) at ./10.6/sql/table_cache.cc:411 #9 0x0000562475c681e2 in tdc_acquire_share (thd=0x5624782af6d8, tl=0x7f8e28002590, flags=1, out_table=0x7f8e329f1338) at ./10.6/sql/table_cache.cc:883 #10 0x00005624758d758a in open_table (thd=0x5624782af6d8, table_list=0x7f8e28002590, ot_ctx=0x7f8e329f1620) at ./10.6/sql/sql_base.cc:1901 #11 0x0000562475911225 in open_purge_table (thd=0x5624782af6d8, db=0x7f8e329f16b0 "test", dblen=4, tb=0x7f8e329f1780 "t1", tblen=2) at ./10.6/sql/sql_class.cc:4968 #12 0x0000562476126b86 in innodb_find_table_for_vc (thd=0x5624782af6d8, table=0x7f8e0c039920) at ./10.6/storage/innobase/handler/ha_innodb.cc:20051 #13 0x0000562476126e33 in innobase_allocate_row_for_vcol (thd=0x5624782af6d8, index=0x7f8e0c00caf0, heap=0x7f8e329f1980, table=0x7f8e329f1928, storage=0x7f8e329f1960) at ./10.6/storage/innobase/handler/ha_innodb.cc:20124 #14 0x00005624762c16b0 in ib_vcol_row::record (this=0x7f8e329f1960, thd=0x5624782af6d8, index=0x7f8e0c00caf0, table=0x7f8e329f1928) at ./10.6/storage/innobase/include/row0mysql.h:763 #15 0x0000562476344720 in row_vers_build_clust_v_col (row=0x7f8e28002100, clust_index=0x7f8e0c18cdc0, index=0x7f8e0c00caf0, heap=0x7f8e28002060) at ./10.6/storage/innobase/row/row0vers.cc:466 #16 0x0000562476345d90 in row_vers_old_has_index_entry (also_curr=true, rec=0x7f8e3893407d "\200", mtr=0x7f8e329f1ac0, index=0x7f8e0c00caf0, ientry=0x7f8e280016d0, roll_ptr=844424950251792, trx_id=18) at ./10.6/storage/innobase/row/row0vers.cc:971 #17 0x0000562476302186 in row_purge_poss_sec (node=0x56247817ac48, index=0x7f8e0c00caf0, entry=0x7f8e280016d0, sec_pcur=0x7f8e329f1ec0, sec_mtr=0x7f8e329f2140, is_tree=false) at ./10.6/storage/innobase/row/row0purge.cc:316 #18 0x000056247630298b in row_purge_remove_sec_if_poss_leaf (node=0x56247817ac48, index=0x7f8e0c00caf0, entry=0x7f8e280016d0) at ./10.6/storage/innobase/row/row0purge.cc:481 #19 0x0000562476302e1d in row_purge_remove_sec_if_poss (node=0x56247817ac48, index=0x7f8e0c00caf0, entry=0x7f8e280016d0) at ./10.6/storage/innobase/row/row0purge.cc:575 #20 0x0000562476302f53 in row_purge_del_mark (node=0x56247817ac48) at ./10.6/storage/innobase/row/row0purge.cc:621 #21 0x0000562476305120 in row_purge_record_func (node=0x56247817ac48, undo_rec=0x7f8e384c8110 "\001?\016", thr=0x56247817aba8, updated_extern=false) at ./10.6/storage/innobase/row/row0purge.cc:1125 #22 0x00005624763053d0 in row_purge (node=0x56247817ac48, undo_rec=0x7f8e384c8110 "\001?\016", thr=0x56247817aba8) at ./10.6/storage/innobase/row/row0purge.cc:1186 check_trx_exists() creates new trx_t object if THD does not contain it. This object will never be freed and deregistered, because at one hand ha_innobase::extra() does not process HA_EXTRA_IS_ATTACHED_CHILDREN, and at the other hand purge_worker_callback() just invokes release_thd(), which does not free thd's trx_t object. So, after gcol.gcol_purge test execution trx_sys.trx_list contains the transaction, created with the above stack trace. "SHOW ENGINE INNODB STATUS" from innodb.gap_lock iterates trx_sys.trx_list from the beginning. In innodb.gap_lock "CREATE TABLE" creates trx_t object with trx_create(), pushes it in front of trx_sys_t::trx_list and assigns it to the connection's THD(the trx_t object is supposed to be deregistered, i.e. removed from trx_sys.trx_list, on disconnection, when the THD is deinitialized). So, when "SHOW ENGINE INNODB STATUS" is executed, trx_sys_t::trx_list contains two trx_t objects in the following order: created with "CREATE TABLE" in innodb.gap_lock, created with the above stack trace in gcol.gcol_purge. The latter transaction does not hold any locks. And this is the order in which "SHOW ENGINE INNODB STATUS" outputs information about the transactions. Regular expression --replace_regex /.*(\d+ lock struct...), heap size \d+(, \d+ row lock...).*/\1\2/ in innodb.gap_lock is greedy, and shows only the last transaction info in the list, and, as the last transaction does not hold any locks, the test fails. As a fix I would propose not to invoke check_trx_exists() from ha_innobase::extra() if operation is ignored.

            Duplicates MDEV-28682.

            vlad.lesin Vladislav Lesin added a comment - Duplicates MDEV-28682 .

            People

              vlad.lesin Vladislav Lesin
              vlad.lesin Vladislav Lesin
              Votes:
              0 Vote for this issue
              Watchers:
              1 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.