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

XA: Assertion `!log->same_pk' failed in row_log_table_apply_delete

Details

    Description

      Apparently belongs to the MDEV-14693 family.

      The test is non-deterministic, run with --repeat=N. N=10 is usually enough for me, but it can vary on different machines.

      --source include/have_innodb.inc
       
      CREATE TABLE t1 (a INT) ENGINE=InnoDB;
      INSERT INTO t1 VALUES (1),(2);
       
      --connect (con1,localhost,root,,test)
      XA START 'xid';
      UPDATE t1 SET a = 5;
       
      --connection default
      SET innodb_lock_wait_timeout= 2, lock_wait_timeout= 2;
      --error ER_NO_SUCH_TABLE
      ALTER TABLE non_existing_table1;
      --send
        ALTER TABLE t1 FORCE;
       
      --connection con1
      --error ER_XAER_RMFAIL
      ALTER TABLE non_existing_table2;
      DELETE FROM t1 LIMIT 1;
       
      --connection default
      --error ER_LOCK_WAIT_TIMEOUT
      --reap
       
      # Cleanup
      --connection con1
      XA END 'xid';
      XA ROLLBACK 'xid';
      DROP TABLE t1;
      --disconnect con1
      

      10.2 a050189773c9

      mysqld: /data/src/10.2/storage/innobase/row/row0log.cc:1884: dberr_t row_log_table_apply_delete(que_thr_t*, ulint, const mrec_t*, const ulint*, mem_heap_t*, mem_heap_t*, const row_log_t*, const row_ext_t*, ulint): Assertion `!log->same_pk' failed.
       
      #7  0x00007fdcdc075ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
      #8  0x000055fe179772fd in row_log_table_apply_delete (thr=0x7fdc7c0362c0, trx_id_col=1, mrec=0x7fdcd404f007 "", moffsets=0x7fdc7c068600, offsets_heap=0x7fdc7c05e0c0, heap=0x7fdc7c05a030, log=0x7fdc7c039f10, save_ext=0x0, ext_size=0) at /data/src/10.2/storage/innobase/row/row0log.cc:1884
      #9  0x000055fe17978a00 in row_log_table_apply_op (thr=0x7fdc7c0362c0, trx_id_col=1, new_trx_id_col=1, dup=0x7fdcd44de2e0, error=0x7fdcd44de084, offsets_heap=0x7fdc7c05e0c0, heap=0x7fdc7c05a030, mrec=0x7fdcd404f007 "", mrec_end=0x7fdcd404f01a "", offsets=0x7fdc7c068600) at /data/src/10.2/storage/innobase/row/row0log.cc:2398
      #10 0x000055fe1797a4bf in row_log_table_apply_ops (thr=0x7fdc7c0362c0, dup=0x7fdcd44de2e0, stage=0x7fdc7c113ce0) at /data/src/10.2/storage/innobase/row/row0log.cc:2909
      #11 0x000055fe1797a9ca in row_log_table_apply (thr=0x7fdc7c0362c0, old_table=0x7fdc7c067ff8, table=0x7fdc7c11a880, stage=0x7fdc7c113ce0) at /data/src/10.2/storage/innobase/row/row0log.cc:3008
      #12 0x000055fe178618ae in ha_innobase::inplace_alter_table (this=0x7fdc7c130d08, altered_table=0x7fdc7c11a880, ha_alter_info=0x7fdcd44de610) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:6488
      #13 0x000055fe173778f7 in handler::ha_inplace_alter_table (this=0x7fdc7c130d08, altered_table=0x7fdc7c11a880, ha_alter_info=0x7fdcd44de610) at /data/src/10.2/sql/handler.h:3775
      #14 0x000055fe1736e7b1 in mysql_inplace_alter_table (thd=0x7fdc7c000b00, table_list=0x7fdc7c0125d0, table=0x7fdc7c130100, altered_table=0x7fdc7c11a880, ha_alter_info=0x7fdcd44de610, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fdcd44de680, alter_ctx=0x7fdcd44df240) at /data/src/10.2/sql/sql_table.cc:7332
      #15 0x000055fe17373de4 in mysql_alter_table (thd=0x7fdc7c000b00, new_db=0x7fdc7c012be0 "test", new_name=0x0, create_info=0x7fdcd44dfe50, table_list=0x7fdc7c0125d0, alter_info=0x7fdcd44dfda0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9353
      #16 0x000055fe173ed954 in Sql_cmd_alter_table::execute (this=0x7fdc7c012be8, thd=0x7fdc7c000b00) at /data/src/10.2/sql/sql_alter.cc:324
      #17 0x000055fe172a8c57 in mysql_execute_command (thd=0x7fdc7c000b00) at /data/src/10.2/sql/sql_parse.cc:6208
      #18 0x000055fe172ad5d1 in mysql_parse (thd=0x7fdc7c000b00, rawbuf=0x7fdc7c0124f8 "ALTER TABLE t1 FORCE", length=20, parser_state=0x7fdcd44e1200, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7902
      #19 0x000055fe1729b4f1 in dispatch_command (command=COM_QUERY, thd=0x7fdc7c000b00, packet=0x7fdc7c008951 "ALTER TABLE t1 FORCE", packet_length=20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1806
      #20 0x000055fe17299e54 in do_command (thd=0x7fdc7c000b00) at /data/src/10.2/sql/sql_parse.cc:1360
      #21 0x000055fe173e8646 in do_handle_one_connection (connect=0x55fe19bc8250) at /data/src/10.2/sql/sql_connect.cc:1335
      #22 0x000055fe173e83d3 in handle_one_connection (arg=0x55fe19bc8250) at /data/src/10.2/sql/sql_connect.cc:1241
      #23 0x000055fe178081f8 in pfs_spawn_thread (arg=0x55fe19bd27c0) at /data/src/10.2/storage/perfschema/pfs.cc:1862
      #24 0x00007fdcddd4c494 in start_thread (arg=0x7fdcd44e2700) at pthread_create.c:333
      #25 0x00007fdcdc13293f in clone () from /lib/x86_64-linux-gnu/libc.so.6
      

      Also reproducible on 10.0, 10.1. Could not reproduce on 5.5, 10.3, MySQL 5.6.

      Attachments

        Issue Links

          Activity

            elenst Elena Stepanova created issue -
            elenst Elena Stepanova made changes -
            Field Original Value New Value
            Description _The test is non-deterministic, run with --repeat=N. N=10 is usually enough for me, but it can vary on different machines._
            {code:sql}
            --source include/have_innodb.inc

            CREATE TABLE t1 (a INT) ENGINE=InnoDB;
            INSERT INTO t1 VALUES (1),(2);

            --connect (con1,localhost,root,,test)
            XA START 'xid';
            UPDATE t1 SET a = 5;

            --connection default
            SET innodb_lock_wait_timeout= 2, lock_wait_timeout= 2;
            --error ER_NO_SUCH_TABLE
            ALTER TABLE non_existing_table1;
            --send
              ALTER TABLE t1 FORCE;

            --connection con1
            --error ER_XAER_RMFAIL
            ALTER TABLE non_existing_table2;
            DELETE FROM t1 LIMIT 1;

            --connection default
            --error ER_LOCK_WAIT_TIMEOUT
            --reap

            # Cleanup
            --connection con1
            XA END 'xid';
            XA ROLLBACK 'xid';
            DROP TABLE t1;
            --disconnect con1
            {code}

            {noformat:title=10.2 a050189773c9}
            mysqld: /data/src/10.2/storage/innobase/row/row0log.cc:1884: dberr_t row_log_table_apply_delete(que_thr_t*, ulint, const mrec_t*, const ulint*, mem_heap_t*, mem_heap_t*, const row_log_t*, const row_ext_t*, ulint): Assertion `!log->same_pk' failed.

            #7 0x00007fdcdc075ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
            #8 0x000055fe179772fd in row_log_table_apply_delete (thr=0x7fdc7c0362c0, trx_id_col=1, mrec=0x7fdcd404f007 "", moffsets=0x7fdc7c068600, offsets_heap=0x7fdc7c05e0c0, heap=0x7fdc7c05a030, log=0x7fdc7c039f10, save_ext=0x0, ext_size=0) at /data/src/10.2/storage/innobase/row/row0log.cc:1884
            #9 0x000055fe17978a00 in row_log_table_apply_op (thr=0x7fdc7c0362c0, trx_id_col=1, new_trx_id_col=1, dup=0x7fdcd44de2e0, error=0x7fdcd44de084, offsets_heap=0x7fdc7c05e0c0, heap=0x7fdc7c05a030, mrec=0x7fdcd404f007 "", mrec_end=0x7fdcd404f01a "", offsets=0x7fdc7c068600) at /data/src/10.2/storage/innobase/row/row0log.cc:2398
            #10 0x000055fe1797a4bf in row_log_table_apply_ops (thr=0x7fdc7c0362c0, dup=0x7fdcd44de2e0, stage=0x7fdc7c113ce0) at /data/src/10.2/storage/innobase/row/row0log.cc:2909
            #11 0x000055fe1797a9ca in row_log_table_apply (thr=0x7fdc7c0362c0, old_table=0x7fdc7c067ff8, table=0x7fdc7c11a880, stage=0x7fdc7c113ce0) at /data/src/10.2/storage/innobase/row/row0log.cc:3008
            #12 0x000055fe178618ae in ha_innobase::inplace_alter_table (this=0x7fdc7c130d08, altered_table=0x7fdc7c11a880, ha_alter_info=0x7fdcd44de610) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:6488
            #13 0x000055fe173778f7 in handler::ha_inplace_alter_table (this=0x7fdc7c130d08, altered_table=0x7fdc7c11a880, ha_alter_info=0x7fdcd44de610) at /data/src/10.2/sql/handler.h:3775
            #14 0x000055fe1736e7b1 in mysql_inplace_alter_table (thd=0x7fdc7c000b00, table_list=0x7fdc7c0125d0, table=0x7fdc7c130100, altered_table=0x7fdc7c11a880, ha_alter_info=0x7fdcd44de610, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fdcd44de680, alter_ctx=0x7fdcd44df240) at /data/src/10.2/sql/sql_table.cc:7332
            #15 0x000055fe17373de4 in mysql_alter_table (thd=0x7fdc7c000b00, new_db=0x7fdc7c012be0 "test", new_name=0x0, create_info=0x7fdcd44dfe50, table_list=0x7fdc7c0125d0, alter_info=0x7fdcd44dfda0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9353
            #16 0x000055fe173ed954 in Sql_cmd_alter_table::execute (this=0x7fdc7c012be8, thd=0x7fdc7c000b00) at /data/src/10.2/sql/sql_alter.cc:324
            #17 0x000055fe172a8c57 in mysql_execute_command (thd=0x7fdc7c000b00) at /data/src/10.2/sql/sql_parse.cc:6208
            #18 0x000055fe172ad5d1 in mysql_parse (thd=0x7fdc7c000b00, rawbuf=0x7fdc7c0124f8 "ALTER TABLE t1 FORCE", length=20, parser_state=0x7fdcd44e1200, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7902
            #19 0x000055fe1729b4f1 in dispatch_command (command=COM_QUERY, thd=0x7fdc7c000b00, packet=0x7fdc7c008951 "ALTER TABLE t1 FORCE", packet_length=20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1806
            #20 0x000055fe17299e54 in do_command (thd=0x7fdc7c000b00) at /data/src/10.2/sql/sql_parse.cc:1360
            #21 0x000055fe173e8646 in do_handle_one_connection (connect=0x55fe19bc8250) at /data/src/10.2/sql/sql_connect.cc:1335
            #22 0x000055fe173e83d3 in handle_one_connection (arg=0x55fe19bc8250) at /data/src/10.2/sql/sql_connect.cc:1241
            #23 0x000055fe178081f8 in pfs_spawn_thread (arg=0x55fe19bd27c0) at /data/src/10.2/storage/perfschema/pfs.cc:1862
            #24 0x00007fdcddd4c494 in start_thread (arg=0x7fdcd44e2700) at pthread_create.c:333
            #25 0x00007fdcdc13293f in clone () from /lib/x86_64-linux-gnu/libc.so.6
            {noformat}

            Also reproducible on 10.0, 10.1. Could not reproduce on 5.5, 10.3, MySQL 5.6.
            _Apparently belongs to the MDEV-14693 family._

            _The test is non-deterministic, run with --repeat=N. N=10 is usually enough for me, but it can vary on different machines._
            {code:sql}
            --source include/have_innodb.inc

            CREATE TABLE t1 (a INT) ENGINE=InnoDB;
            INSERT INTO t1 VALUES (1),(2);

            --connect (con1,localhost,root,,test)
            XA START 'xid';
            UPDATE t1 SET a = 5;

            --connection default
            SET innodb_lock_wait_timeout= 2, lock_wait_timeout= 2;
            --error ER_NO_SUCH_TABLE
            ALTER TABLE non_existing_table1;
            --send
              ALTER TABLE t1 FORCE;

            --connection con1
            --error ER_XAER_RMFAIL
            ALTER TABLE non_existing_table2;
            DELETE FROM t1 LIMIT 1;

            --connection default
            --error ER_LOCK_WAIT_TIMEOUT
            --reap

            # Cleanup
            --connection con1
            XA END 'xid';
            XA ROLLBACK 'xid';
            DROP TABLE t1;
            --disconnect con1
            {code}

            {noformat:title=10.2 a050189773c9}
            mysqld: /data/src/10.2/storage/innobase/row/row0log.cc:1884: dberr_t row_log_table_apply_delete(que_thr_t*, ulint, const mrec_t*, const ulint*, mem_heap_t*, mem_heap_t*, const row_log_t*, const row_ext_t*, ulint): Assertion `!log->same_pk' failed.

            #7 0x00007fdcdc075ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
            #8 0x000055fe179772fd in row_log_table_apply_delete (thr=0x7fdc7c0362c0, trx_id_col=1, mrec=0x7fdcd404f007 "", moffsets=0x7fdc7c068600, offsets_heap=0x7fdc7c05e0c0, heap=0x7fdc7c05a030, log=0x7fdc7c039f10, save_ext=0x0, ext_size=0) at /data/src/10.2/storage/innobase/row/row0log.cc:1884
            #9 0x000055fe17978a00 in row_log_table_apply_op (thr=0x7fdc7c0362c0, trx_id_col=1, new_trx_id_col=1, dup=0x7fdcd44de2e0, error=0x7fdcd44de084, offsets_heap=0x7fdc7c05e0c0, heap=0x7fdc7c05a030, mrec=0x7fdcd404f007 "", mrec_end=0x7fdcd404f01a "", offsets=0x7fdc7c068600) at /data/src/10.2/storage/innobase/row/row0log.cc:2398
            #10 0x000055fe1797a4bf in row_log_table_apply_ops (thr=0x7fdc7c0362c0, dup=0x7fdcd44de2e0, stage=0x7fdc7c113ce0) at /data/src/10.2/storage/innobase/row/row0log.cc:2909
            #11 0x000055fe1797a9ca in row_log_table_apply (thr=0x7fdc7c0362c0, old_table=0x7fdc7c067ff8, table=0x7fdc7c11a880, stage=0x7fdc7c113ce0) at /data/src/10.2/storage/innobase/row/row0log.cc:3008
            #12 0x000055fe178618ae in ha_innobase::inplace_alter_table (this=0x7fdc7c130d08, altered_table=0x7fdc7c11a880, ha_alter_info=0x7fdcd44de610) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:6488
            #13 0x000055fe173778f7 in handler::ha_inplace_alter_table (this=0x7fdc7c130d08, altered_table=0x7fdc7c11a880, ha_alter_info=0x7fdcd44de610) at /data/src/10.2/sql/handler.h:3775
            #14 0x000055fe1736e7b1 in mysql_inplace_alter_table (thd=0x7fdc7c000b00, table_list=0x7fdc7c0125d0, table=0x7fdc7c130100, altered_table=0x7fdc7c11a880, ha_alter_info=0x7fdcd44de610, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fdcd44de680, alter_ctx=0x7fdcd44df240) at /data/src/10.2/sql/sql_table.cc:7332
            #15 0x000055fe17373de4 in mysql_alter_table (thd=0x7fdc7c000b00, new_db=0x7fdc7c012be0 "test", new_name=0x0, create_info=0x7fdcd44dfe50, table_list=0x7fdc7c0125d0, alter_info=0x7fdcd44dfda0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9353
            #16 0x000055fe173ed954 in Sql_cmd_alter_table::execute (this=0x7fdc7c012be8, thd=0x7fdc7c000b00) at /data/src/10.2/sql/sql_alter.cc:324
            #17 0x000055fe172a8c57 in mysql_execute_command (thd=0x7fdc7c000b00) at /data/src/10.2/sql/sql_parse.cc:6208
            #18 0x000055fe172ad5d1 in mysql_parse (thd=0x7fdc7c000b00, rawbuf=0x7fdc7c0124f8 "ALTER TABLE t1 FORCE", length=20, parser_state=0x7fdcd44e1200, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7902
            #19 0x000055fe1729b4f1 in dispatch_command (command=COM_QUERY, thd=0x7fdc7c000b00, packet=0x7fdc7c008951 "ALTER TABLE t1 FORCE", packet_length=20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1806
            #20 0x000055fe17299e54 in do_command (thd=0x7fdc7c000b00) at /data/src/10.2/sql/sql_parse.cc:1360
            #21 0x000055fe173e8646 in do_handle_one_connection (connect=0x55fe19bc8250) at /data/src/10.2/sql/sql_connect.cc:1335
            #22 0x000055fe173e83d3 in handle_one_connection (arg=0x55fe19bc8250) at /data/src/10.2/sql/sql_connect.cc:1241
            #23 0x000055fe178081f8 in pfs_spawn_thread (arg=0x55fe19bd27c0) at /data/src/10.2/storage/perfschema/pfs.cc:1862
            #24 0x00007fdcddd4c494 in start_thread (arg=0x7fdcd44e2700) at pthread_create.c:333
            #25 0x00007fdcdc13293f in clone () from /lib/x86_64-linux-gnu/libc.so.6
            {noformat}

            Also reproducible on 10.0, 10.1. Could not reproduce on 5.5, 10.3, MySQL 5.6.
            elenst Elena Stepanova made changes -
            elenst Elena Stepanova made changes -
            elenst Elena Stepanova made changes -
            elenst Elena Stepanova made changes -
            Assignee Elena Stepanova [ elenst ] Sergei Golubchik [ serg ]
            elenst Elena Stepanova made changes -
            alice Alice Sherepa added a comment -

            10.2 a241d411951f72d6cdbe8fa

            mysqld: /10.2/storage/innobase/row/row0log.cc:1818: dberr_t row_log_table_apply_delete(ulint, const mrec_t*, const offset_t*, mem_heap_t*, mem_heap_t*, const row_log_t*): Assertion `!log->same_pk' failed.
            

            alice Alice Sherepa added a comment - 10.2 a241d411951f72d6cdbe8fa mysqld: /10.2/storage/innobase/row/row0log.cc:1818: dberr_t row_log_table_apply_delete(ulint, const mrec_t*, const offset_t*, mem_heap_t*, mem_heap_t*, const row_log_t*): Assertion `!log->same_pk' failed.
            alice Alice Sherepa made changes -
            Status Open [ 1 ] Confirmed [ 10101 ]
            marko Marko Mäkelä made changes -
            elenst Elena Stepanova added a comment - - edited

            A similar alternative test case to try in case the original one doesn't fail:

            --source include/have_innodb.inc
             
            CREATE TABLE t1 (col1 INT, col2 INT, PRIMARY KEY(col1)) ENGINE=InnoDB;
            INSERT INTO t1 VALUES (3, 3);
            XA START 'x';
            DELETE FROM t1 WHERE col2 = 3;
             
            --connect (con1,localhost,root,,test)
            SET innodb_lock_wait_timeout= 1;
            --send
              INSERT INTO t1 VALUES (1, 0);
             
            --connection default
            INSERT INTO t1 VALUES (3, 3);
            --error ER_XAER_RMFAIL
            COMMIT;
             
            --connect (con2,localhost,root,,test)
            SET lock_wait_timeout= 3;
            --send
              ALTER TABLE t1 DROP COLUMN col2;
             
            --connection default
            --sleep 1
            DELETE FROM t1 WHERE col1 = 3;
             
            --connection con2
            --error ER_LOCK_WAIT_TIMEOUT
            --reap
             
            # Cleanup
            --disconnect con2
            --disconnect con1
            --connection default
            XA END 'x';
            XA ROLLBACK 'x';
            DROP TABLE t1;
            

            10.2 b3b1c51e4d

            (rr) bt
            #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
            #1  0x00007fd44be638b1 in __GI_abort () at abort.c:79
            #2  0x00007fd44be5342a in __assert_fail_base (fmt=0x7fd44bfdaa38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x5587dacecd16 "!log->same_pk", 
                file=file@entry=0x5587dacec178 "/home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc", line=line@entry=1830, 
                function=function@entry=0x5587dacefc40 <row_log_table_apply_delete(unsigned long, unsigned char const*, unsigned short const*, mem_block_info_t*, mem_block_info_t*, row_log_t const*)::__PRETTY_FUNCTION__> "dberr_t row_log_table_apply_delete(ulint, const mrec_t*, const rec_offs*, mem_heap_t*, mem_heap_t*, const row_log_t*)") at assert.c:92
            #3  0x00007fd44be534a2 in __GI___assert_fail (assertion=0x5587dacecd16 "!log->same_pk", file=0x5587dacec178 "/home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc", 
                line=1830, 
                function=0x5587dacefc40 <row_log_table_apply_delete(unsigned long, unsigned char const*, unsigned short const*, mem_block_info_t*, mem_block_info_t*, row_log_t const*)::__PRETTY_FUNCTION__> "dberr_t row_log_table_apply_delete(ulint, const mrec_t*, const rec_offs*, mem_heap_t*, mem_heap_t*, const row_log_t*)") at assert.c:101
            #4  0x00005587da6af02f in row_log_table_apply_delete (trx_id_col=1, mrec=0x7fd3f9259002 "\200", moffsets=0x7fd3d002b880, offsets_heap=0x7fd3d0055d30, heap=0x7fd3d0051ca0, 
                log=0x7fd3d0031b80) at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:1830
            #5  0x00005587da6b0647 in row_log_table_apply_op (thr=0x7fd3d0029768, trx_id_col=1, new_trx_id_col=1, dup=0x7fd41c0aaca0, error=0x7fd41c0aaa24, offsets_heap=0x7fd3d0055d30, 
                heap=0x7fd3d0051ca0, mrec=0x7fd3f9259002 "\200", mrec_end=0x7fd3f9259013 "", offsets=0x7fd3d002b880) at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:2314
            #6  0x00005587da6b212b in row_log_table_apply_ops (thr=0x7fd3d0029768, dup=0x7fd41c0aaca0, stage=0x7fd3d002ae30)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:2833
            #7  0x00005587da6b263c in row_log_table_apply (thr=0x7fd3d0029768, old_table=0x7fd3d8194610, table=0x7fd3d0025880, stage=0x7fd3d002ae30)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:2935
            #8  0x00005587da599ac8 in ha_innobase::inplace_alter_table (this=0x7fd3d00195a8, altered_table=0x7fd3d0025880, ha_alter_info=0x7fd41c0ab010)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/handler/handler0alter.cc:6280
            #9  0x00005587da1bf9f5 in handler::ha_inplace_alter_table (this=0x7fd3d00195a8, altered_table=0x7fd3d0025880, ha_alter_info=0x7fd41c0ab010)
                at /home/mariadb/log_table_apply/10.2/sql/handler.h:3790
            #10 0x00005587da1b5036 in mysql_inplace_alter_table (thd=0x7fd3d0000d50, table_list=0x7fd3d00113e0, table=0x7fd3d0018540, altered_table=0x7fd3d0025880, ha_alter_info=0x7fd41c0ab010, 
                inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fd41c0ab0a0, alter_ctx=0x7fd41c0ab650) at /home/mariadb/log_table_apply/10.2/sql/sql_table.cc:7453
            #11 0x00005587da1badf2 in mysql_alter_table (thd=0x7fd3d0000d50, new_db=0x7fd3d00119f8 "test", new_name=0x0, create_info=0x7fd41c0ac270, table_list=0x7fd3d00113e0, 
                alter_info=0x7fd41c0ac1c0, order_num=0, order=0x0, ignore=false) at /home/mariadb/log_table_apply/10.2/sql/sql_table.cc:9622
            #12 0x00005587da23775d in Sql_cmd_alter_table::execute (this=0x7fd3d0011a28, thd=0x7fd3d0000d50) at /home/mariadb/log_table_apply/10.2/sql/sql_alter.cc:333
            #13 0x00005587da0ea43f in mysql_execute_command (thd=0x7fd3d0000d50) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:5964
            #14 0x00005587da0ef3d7 in mysql_parse (thd=0x7fd3d0000d50, rawbuf=0x7fd3d00112f8 "ALTER TABLE t1 DROP COLUMN col2", length=31, parser_state=0x7fd41c0ad5f0, is_com_multi=false, 
                is_next_command=false) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:7733
            #15 0x00005587da0dd6e3 in dispatch_command (command=COM_QUERY, thd=0x7fd3d0000d50, packet=0x7fd3d0008b11 "ALTER TABLE t1 DROP COLUMN col2", packet_length=31, is_com_multi=false, 
                is_next_command=false) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:1823
            #16 0x00005587da0dc160 in do_command (thd=0x7fd3d0000d50) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:1377
            #17 0x00005587da2322e3 in do_handle_one_connection (connect=0x5587de2894e0) at /home/mariadb/log_table_apply/10.2/sql/sql_connect.cc:1336
            #18 0x00005587da23204e in handle_one_connection (arg=0x5587de2894e0) at /home/mariadb/log_table_apply/10.2/sql/sql_connect.cc:1241
            #19 0x00005587daa485c7 in pfs_spawn_thread (arg=0x5587de2905d0) at /home/mariadb/log_table_apply/10.2/storage/perfschema/pfs.cc:1869
            #20 0x00007fd44cb5a6db in start_thread (arg=0x7fd41c0ae700) at pthread_create.c:463
            #21 0x00007fd44bf44a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
            

            Reproducible on 10.1, 10.2. Couldn't reproduce on 10.3.

            elenst Elena Stepanova added a comment - - edited A similar alternative test case to try in case the original one doesn't fail: --source include/have_innodb.inc   CREATE TABLE t1 (col1 INT , col2 INT , PRIMARY KEY (col1)) ENGINE=InnoDB; INSERT INTO t1 VALUES (3, 3); XA START 'x' ; DELETE FROM t1 WHERE col2 = 3;   --connect (con1,localhost,root,,test) SET innodb_lock_wait_timeout= 1; --send INSERT INTO t1 VALUES (1, 0);   --connection default INSERT INTO t1 VALUES (3, 3); --error ER_XAER_RMFAIL COMMIT ;   --connect (con2,localhost,root,,test) SET lock_wait_timeout= 3; --send ALTER TABLE t1 DROP COLUMN col2;   --connection default --sleep 1 DELETE FROM t1 WHERE col1 = 3;   --connection con2 --error ER_LOCK_WAIT_TIMEOUT --reap   # Cleanup --disconnect con2 --disconnect con1 --connection default XA END 'x' ; XA ROLLBACK 'x' ; DROP TABLE t1; 10.2 b3b1c51e4d (rr) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 #1 0x00007fd44be638b1 in __GI_abort () at abort.c:79 #2 0x00007fd44be5342a in __assert_fail_base (fmt=0x7fd44bfdaa38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x5587dacecd16 "!log->same_pk", file=file@entry=0x5587dacec178 "/home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc", line=line@entry=1830, function=function@entry=0x5587dacefc40 <row_log_table_apply_delete(unsigned long, unsigned char const*, unsigned short const*, mem_block_info_t*, mem_block_info_t*, row_log_t const*)::__PRETTY_FUNCTION__> "dberr_t row_log_table_apply_delete(ulint, const mrec_t*, const rec_offs*, mem_heap_t*, mem_heap_t*, const row_log_t*)") at assert.c:92 #3 0x00007fd44be534a2 in __GI___assert_fail (assertion=0x5587dacecd16 "!log->same_pk", file=0x5587dacec178 "/home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc", line=1830, function=0x5587dacefc40 <row_log_table_apply_delete(unsigned long, unsigned char const*, unsigned short const*, mem_block_info_t*, mem_block_info_t*, row_log_t const*)::__PRETTY_FUNCTION__> "dberr_t row_log_table_apply_delete(ulint, const mrec_t*, const rec_offs*, mem_heap_t*, mem_heap_t*, const row_log_t*)") at assert.c:101 #4 0x00005587da6af02f in row_log_table_apply_delete (trx_id_col=1, mrec=0x7fd3f9259002 "\200", moffsets=0x7fd3d002b880, offsets_heap=0x7fd3d0055d30, heap=0x7fd3d0051ca0, log=0x7fd3d0031b80) at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:1830 #5 0x00005587da6b0647 in row_log_table_apply_op (thr=0x7fd3d0029768, trx_id_col=1, new_trx_id_col=1, dup=0x7fd41c0aaca0, error=0x7fd41c0aaa24, offsets_heap=0x7fd3d0055d30, heap=0x7fd3d0051ca0, mrec=0x7fd3f9259002 "\200", mrec_end=0x7fd3f9259013 "", offsets=0x7fd3d002b880) at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:2314 #6 0x00005587da6b212b in row_log_table_apply_ops (thr=0x7fd3d0029768, dup=0x7fd41c0aaca0, stage=0x7fd3d002ae30) at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:2833 #7 0x00005587da6b263c in row_log_table_apply (thr=0x7fd3d0029768, old_table=0x7fd3d8194610, table=0x7fd3d0025880, stage=0x7fd3d002ae30) at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:2935 #8 0x00005587da599ac8 in ha_innobase::inplace_alter_table (this=0x7fd3d00195a8, altered_table=0x7fd3d0025880, ha_alter_info=0x7fd41c0ab010) at /home/mariadb/log_table_apply/10.2/storage/innobase/handler/handler0alter.cc:6280 #9 0x00005587da1bf9f5 in handler::ha_inplace_alter_table (this=0x7fd3d00195a8, altered_table=0x7fd3d0025880, ha_alter_info=0x7fd41c0ab010) at /home/mariadb/log_table_apply/10.2/sql/handler.h:3790 #10 0x00005587da1b5036 in mysql_inplace_alter_table (thd=0x7fd3d0000d50, table_list=0x7fd3d00113e0, table=0x7fd3d0018540, altered_table=0x7fd3d0025880, ha_alter_info=0x7fd41c0ab010, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fd41c0ab0a0, alter_ctx=0x7fd41c0ab650) at /home/mariadb/log_table_apply/10.2/sql/sql_table.cc:7453 #11 0x00005587da1badf2 in mysql_alter_table (thd=0x7fd3d0000d50, new_db=0x7fd3d00119f8 "test", new_name=0x0, create_info=0x7fd41c0ac270, table_list=0x7fd3d00113e0, alter_info=0x7fd41c0ac1c0, order_num=0, order=0x0, ignore=false) at /home/mariadb/log_table_apply/10.2/sql/sql_table.cc:9622 #12 0x00005587da23775d in Sql_cmd_alter_table::execute (this=0x7fd3d0011a28, thd=0x7fd3d0000d50) at /home/mariadb/log_table_apply/10.2/sql/sql_alter.cc:333 #13 0x00005587da0ea43f in mysql_execute_command (thd=0x7fd3d0000d50) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:5964 #14 0x00005587da0ef3d7 in mysql_parse (thd=0x7fd3d0000d50, rawbuf=0x7fd3d00112f8 "ALTER TABLE t1 DROP COLUMN col2", length=31, parser_state=0x7fd41c0ad5f0, is_com_multi=false, is_next_command=false) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:7733 #15 0x00005587da0dd6e3 in dispatch_command (command=COM_QUERY, thd=0x7fd3d0000d50, packet=0x7fd3d0008b11 "ALTER TABLE t1 DROP COLUMN col2", packet_length=31, is_com_multi=false, is_next_command=false) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:1823 #16 0x00005587da0dc160 in do_command (thd=0x7fd3d0000d50) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:1377 #17 0x00005587da2322e3 in do_handle_one_connection (connect=0x5587de2894e0) at /home/mariadb/log_table_apply/10.2/sql/sql_connect.cc:1336 #18 0x00005587da23204e in handle_one_connection (arg=0x5587de2894e0) at /home/mariadb/log_table_apply/10.2/sql/sql_connect.cc:1241 #19 0x00005587daa485c7 in pfs_spawn_thread (arg=0x5587de2905d0) at /home/mariadb/log_table_apply/10.2/storage/perfschema/pfs.cc:1869 #20 0x00007fd44cb5a6db in start_thread (arg=0x7fd41c0ae700) at pthread_create.c:463 #21 0x00007fd44bf44a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 Reproducible on 10.1, 10.2. Couldn't reproduce on 10.3.
            elenst Elena Stepanova made changes -
            Labels rr-profile
            elenst Elena Stepanova made changes -
            Assignee Sergei Golubchik [ serg ] Marko Mäkelä [ marko ]

            In the rr replay trace that I analyzed, the problem is the transaction with ID 0x506. Apparently, the COMMIT for XA START 'x' is not being passed to InnoDB, but nevertheless, the MDL would be released, allowing the later ALTER TABLE to proceed. Here is some proof of that:

            10.2 b3b1c51e4de0866bd1baae888eacb86c2d3b3698

            Thread 10 hit Hardware watchpoint 2: trx_sys.rw_trx_list.count
            …
            (rr) up
            #1  0x00005587da75a4c8 in trx_set_rw_mode (trx=0x7fd446c76140)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/trx/trx0trx.cc:3033
            (rr) p/x trx->id
            $28 = 0x506
            (rr) when
            Current event: 177494
            (rr) bt
            #0  0x00005587da75b715 in ut_list_prepend<ut_list_base<trx_t, ut_list_node<trx_t> trx_t::*> > (list=..., elem=0x7fd446c76140)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/include/ut0lst.h:171
            #1  0x00005587da75a4c8 in trx_set_rw_mode (trx=0x7fd446c76140)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/trx/trx0trx.cc:3033
            #2  0x00005587da5dbcd4 in lock_table (flags=0, table=0x7fd3d8194610, 
                mode=LOCK_IX, thr=0x7fd3d80a9f10)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/lock/lock0lock.cc:4033
            #3  0x00005587da6d204a in row_search_mvcc (buf=0x7fd3d8036880 "\377", 
                mode=PAGE_CUR_G, prebuilt=0x7fd3d80a9500, match_mode=0, direction=0)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0sel.cc:4656
            #4  0x00005587da561563 in ha_innobase::index_read (this=0x7fd3d80ac8a8, 
                buf=0x7fd3d8036880 "\377", key_ptr=0x0, key_len=0, 
                find_flag=HA_READ_AFTER_KEY)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/handler/ha_innodb.cc:9394
            #5  0x00005587da5624ac in ha_innobase::index_first (this=0x7fd3d80ac8a8, 
                buf=0x7fd3d8036880 "\377")
                at /home/mariadb/log_table_apply/10.2/storage/innobase/handler/ha_innodb.cc:9771
            #6  0x00005587da5626bb in ha_innobase::rnd_next (this=0x7fd3d80ac8a8, 
                buf=0x7fd3d8036880 "\377")
                at /home/mariadb/log_table_apply/10.2/storage/innobase/handler/ha_innodb.cc:9864
            #7  0x00005587da361d8f in handler::ha_rnd_next (this=0x7fd3d80ac8a8, 
                buf=0x7fd3d8036880 "\377")
                at /home/mariadb/log_table_apply/10.2/sql/handler.cc:2668
            #8  0x00005587da4cc298 in rr_sequential (info=0x7fd43405d2e0)
                at /home/mariadb/log_table_apply/10.2/sql/records.cc:484
            #9  0x00005587da4e7152 in mysql_delete (thd=0x7fd3d8000d50, 
                table_list=0x7fd3d80127a0, conds=0x7fd3d8012f60, 
                order_list=0x7fd3d80052e8, limit=18446744073709551615, options=0, 
                result=0x0) at /home/mariadb/log_table_apply/10.2/sql/sql_delete.cc:559
            #10 0x00005587da0e4866 in mysql_execute_command (thd=0x7fd3d8000d50)
                at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:4362
            #11 0x00005587da0ef3d7 in mysql_parse (thd=0x7fd3d8000d50, 
                rawbuf=0x7fd3d80126b8 "DELETE FROM t1 WHERE col2 = 3", length=29, 
                parser_state=0x7fd43405e5f0, is_com_multi=false, is_next_command=false)
                at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:7733
            …
            (rr) break MDL_context::release_transactional_locks
            Breakpoint 5 at 0x5587da23ff15: file /home/mariadb/log_table_apply/10.2/sql/mdl.cc, line 2844.
            (rr) c
            Continuing.
            …
            Thread 10 hit Breakpoint 5, MDL_context::release_transactional_locks (
                this=0x7fd3d8000e70) at /home/mariadb/log_table_apply/10.2/sql/mdl.cc:2844
            2844	in /home/mariadb/log_table_apply/10.2/sql/mdl.cc
            (rr) bt
            #0  MDL_context::release_transactional_locks (this=0x7fd3d8000e70)
                at /home/mariadb/log_table_apply/10.2/sql/mdl.cc:2844
            #1  0x00005587da0e8151 in mysql_execute_command (thd=0x7fd3d8000d50)
                at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:5300
            #2  0x00005587da0ef3d7 in mysql_parse (thd=0x7fd3d8000d50, 
                rawbuf=0x7fd3d80126b8 "COMMIT", length=6, parser_state=0x7fd43405e5f0, 
                is_com_multi=false, is_next_command=false)
                at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:7733
            …
            (rr) disable
            (rr) continue
            Continuing.
            [New Thread 24963.25317]
             
            Thread 31 received signal SIGABRT, Aborted.
            [Switching to Thread 24963.25317]
            __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
            51	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
            (rr) up 4
            #4  0x00005587da6af02f in row_log_table_apply_delete (trx_id_col=1, 
                mrec=0x7fd3f9259002 "\200", moffsets=0x7fd3d002b880, 
                offsets_heap=0x7fd3d0055d30, heap=0x7fd3d0051ca0, log=0x7fd3d0031b80)
                at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:1830
            1830	/home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc: No such file or directory.
            (rr) p/x *mrec_trx_id@13
            $31 = {0x0, 0x0, 0x0, 0x0, 0x5, 0x6, 0x4, 0x0, 0x0, 0x1, 0x46, 0x1, 0x32}
            

            The immediate reason for the assertion failure is that row_log_table_open() was invoked on a transaction that was supposed to have been terminated before ha_innobase::prepare_inplace_alter_table() was invoked.

            It seems that a simple code change to mysql_execute_command() might fix this:

                bool commit_failed= trans_commit(thd);
                thd->mdl_context.release_transactional_locks();
                if (commit_failed)
                {
                  WSREP_DEBUG("COMMIT failed, MDL released: %lld",
                              (longlong) thd->thread_id);
                  goto error;
                }
            

            Why are we unconditionally releasing the MDL? Obviously, if the COMMIT statement is not allowed, and it is not actually committing the transaction, it should not invoke MDL_context::release_transactional_locks() either. That call should only be allowed after one of handlerton::rollback, handlerton::commit, (or handlerton::commit_by_xid, handlerton::rollback_by_xid if they worked properly with MDL) was executed by the storage engines that have active transactions.

            marko Marko Mäkelä added a comment - In the rr replay trace that I analyzed, the problem is the transaction with ID 0x506. Apparently, the COMMIT for XA START 'x' is not being passed to InnoDB, but nevertheless, the MDL would be released, allowing the later ALTER TABLE to proceed. Here is some proof of that: 10.2 b3b1c51e4de0866bd1baae888eacb86c2d3b3698 Thread 10 hit Hardware watchpoint 2: trx_sys.rw_trx_list.count … (rr) up #1 0x00005587da75a4c8 in trx_set_rw_mode (trx=0x7fd446c76140) at /home/mariadb/log_table_apply/10.2/storage/innobase/trx/trx0trx.cc:3033 (rr) p/x trx->id $28 = 0x506 (rr) when Current event: 177494 (rr) bt #0 0x00005587da75b715 in ut_list_prepend<ut_list_base<trx_t, ut_list_node<trx_t> trx_t::*> > (list=..., elem=0x7fd446c76140) at /home/mariadb/log_table_apply/10.2/storage/innobase/include/ut0lst.h:171 #1 0x00005587da75a4c8 in trx_set_rw_mode (trx=0x7fd446c76140) at /home/mariadb/log_table_apply/10.2/storage/innobase/trx/trx0trx.cc:3033 #2 0x00005587da5dbcd4 in lock_table (flags=0, table=0x7fd3d8194610, mode=LOCK_IX, thr=0x7fd3d80a9f10) at /home/mariadb/log_table_apply/10.2/storage/innobase/lock/lock0lock.cc:4033 #3 0x00005587da6d204a in row_search_mvcc (buf=0x7fd3d8036880 "\377", mode=PAGE_CUR_G, prebuilt=0x7fd3d80a9500, match_mode=0, direction=0) at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0sel.cc:4656 #4 0x00005587da561563 in ha_innobase::index_read (this=0x7fd3d80ac8a8, buf=0x7fd3d8036880 "\377", key_ptr=0x0, key_len=0, find_flag=HA_READ_AFTER_KEY) at /home/mariadb/log_table_apply/10.2/storage/innobase/handler/ha_innodb.cc:9394 #5 0x00005587da5624ac in ha_innobase::index_first (this=0x7fd3d80ac8a8, buf=0x7fd3d8036880 "\377") at /home/mariadb/log_table_apply/10.2/storage/innobase/handler/ha_innodb.cc:9771 #6 0x00005587da5626bb in ha_innobase::rnd_next (this=0x7fd3d80ac8a8, buf=0x7fd3d8036880 "\377") at /home/mariadb/log_table_apply/10.2/storage/innobase/handler/ha_innodb.cc:9864 #7 0x00005587da361d8f in handler::ha_rnd_next (this=0x7fd3d80ac8a8, buf=0x7fd3d8036880 "\377") at /home/mariadb/log_table_apply/10.2/sql/handler.cc:2668 #8 0x00005587da4cc298 in rr_sequential (info=0x7fd43405d2e0) at /home/mariadb/log_table_apply/10.2/sql/records.cc:484 #9 0x00005587da4e7152 in mysql_delete (thd=0x7fd3d8000d50, table_list=0x7fd3d80127a0, conds=0x7fd3d8012f60, order_list=0x7fd3d80052e8, limit=18446744073709551615, options=0, result=0x0) at /home/mariadb/log_table_apply/10.2/sql/sql_delete.cc:559 #10 0x00005587da0e4866 in mysql_execute_command (thd=0x7fd3d8000d50) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:4362 #11 0x00005587da0ef3d7 in mysql_parse (thd=0x7fd3d8000d50, rawbuf=0x7fd3d80126b8 "DELETE FROM t1 WHERE col2 = 3", length=29, parser_state=0x7fd43405e5f0, is_com_multi=false, is_next_command=false) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:7733 … (rr) break MDL_context::release_transactional_locks Breakpoint 5 at 0x5587da23ff15: file /home/mariadb/log_table_apply/10.2/sql/mdl.cc, line 2844. (rr) c Continuing. … Thread 10 hit Breakpoint 5, MDL_context::release_transactional_locks ( this=0x7fd3d8000e70) at /home/mariadb/log_table_apply/10.2/sql/mdl.cc:2844 2844 in /home/mariadb/log_table_apply/10.2/sql/mdl.cc (rr) bt #0 MDL_context::release_transactional_locks (this=0x7fd3d8000e70) at /home/mariadb/log_table_apply/10.2/sql/mdl.cc:2844 #1 0x00005587da0e8151 in mysql_execute_command (thd=0x7fd3d8000d50) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:5300 #2 0x00005587da0ef3d7 in mysql_parse (thd=0x7fd3d8000d50, rawbuf=0x7fd3d80126b8 "COMMIT", length=6, parser_state=0x7fd43405e5f0, is_com_multi=false, is_next_command=false) at /home/mariadb/log_table_apply/10.2/sql/sql_parse.cc:7733 … (rr) disable (rr) continue Continuing. [New Thread 24963.25317]   Thread 31 received signal SIGABRT, Aborted. [Switching to Thread 24963.25317] __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 51 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory. (rr) up 4 #4 0x00005587da6af02f in row_log_table_apply_delete (trx_id_col=1, mrec=0x7fd3f9259002 "\200", moffsets=0x7fd3d002b880, offsets_heap=0x7fd3d0055d30, heap=0x7fd3d0051ca0, log=0x7fd3d0031b80) at /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc:1830 1830 /home/mariadb/log_table_apply/10.2/storage/innobase/row/row0log.cc: No such file or directory. (rr) p/x *mrec_trx_id@13 $31 = {0x0, 0x0, 0x0, 0x0, 0x5, 0x6, 0x4, 0x0, 0x0, 0x1, 0x46, 0x1, 0x32} The immediate reason for the assertion failure is that row_log_table_open() was invoked on a transaction that was supposed to have been terminated before ha_innobase::prepare_inplace_alter_table() was invoked. It seems that a simple code change to mysql_execute_command() might fix this: bool commit_failed= trans_commit(thd); thd->mdl_context.release_transactional_locks(); if (commit_failed) { WSREP_DEBUG( "COMMIT failed, MDL released: %lld" , (longlong) thd->thread_id); goto error; } Why are we unconditionally releasing the MDL? Obviously, if the COMMIT statement is not allowed, and it is not actually committing the transaction, it should not invoke MDL_context::release_transactional_locks() either. That call should only be allowed after one of handlerton::rollback , handlerton::commit , (or handlerton::commit_by_xid , handlerton::rollback_by_xid if they worked properly with MDL) was executed by the storage engines that have active transactions.
            marko Marko Mäkelä made changes -
            Assignee Marko Mäkelä [ marko ] Sergei Golubchik [ serg ]
            Labels rr-profile rr-profile-analyzed
            marko Marko Mäkelä made changes -
            elenst Elena Stepanova made changes -
            Component/s Locking [ 10900 ]
            Assignee Sergei Golubchik [ serg ] Vladislav Vaintroub [ wlad ]
            marko Marko Mäkelä made changes -
            elenst Elena Stepanova added a comment - - edited

            An apparently related problem:

            10.2 caa474f8

            mysqld: /data/src/10.2/storage/innobase/handler/handler0alter.cc:8138: bool alter_rebuild_apply_log(ha_innobase_inplace_ctx*, Alter_inplace_info*, TABLE*): Assertion `err_key < ha_alter_info->key_count' failed.
             
            #7  0x00007fae8d87ff12 in __GI___assert_fail (assertion=0x555a000724f8 "err_key < ha_alter_info->key_count", file=0x555a0006f098 "/data/src/10.2/storage/innobase/handler/handler0alter.cc", line=8138, function=0x555a000752c0 <alter_rebuild_apply_log(ha_innobase_inplace_ctx*, Alter_inplace_info*, TABLE*)::__PRETTY_FUNCTION__> "bool alter_rebuild_apply_log(ha_innobase_inplace_ctx*, Alter_inplace_info*, TABLE*)") at assert.c:101
            #8  0x00005559ff96a9ed in alter_rebuild_apply_log (ctx=0x7fae34013a28, ha_alter_info=0x7fae8808c040, altered_table=0x7fae340d25f0) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:8138
            #9  0x00005559ff96b3c6 in ha_innobase::commit_inplace_alter_table (this=0x7fae380e95f8, altered_table=0x7fae340d25f0, ha_alter_info=0x7fae8808c040, commit=true) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:8316
            #10 0x00005559ff735ccf in handler::ha_commit_inplace_alter_table (this=0x7fae380e95f8, altered_table=0x7fae340d25f0, ha_alter_info=0x7fae8808c040, commit=true) at /data/src/10.2/sql/handler.cc:4378
            #11 0x00005559ff58506c in mysql_inplace_alter_table (thd=0x7fae34000af0, table_list=0x7fae34012698, table=0x7fae381093f0, altered_table=0x7fae340d25f0, ha_alter_info=0x7fae8808c040, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fae8808c0d0, alter_ctx=0x7fae8808c680) at /data/src/10.2/sql/sql_table.cc:7480
            #12 0x00005559ff58aceb in mysql_alter_table (thd=0x7fae34000af0, new_db=0x7fae34012cb0 "test", new_name=0x0, create_info=0x7fae8808d2a0, table_list=0x7fae34012698, alter_info=0x7fae8808d1f0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9622
            #13 0x00005559ff6075d0 in Sql_cmd_alter_table::execute (this=0x7fae34012da0, thd=0x7fae34000af0) at /data/src/10.2/sql/sql_alter.cc:333
            #14 0x00005559ff4ba322 in mysql_execute_command (thd=0x7fae34000af0) at /data/src/10.2/sql/sql_parse.cc:5964
            #15 0x00005559ff4bf2a3 in mysql_parse (thd=0x7fae34000af0, rawbuf=0x7fae340125a0 "ALTER TABLE t1 ADD COLUMN extra INT", length=35, parser_state=0x7fae8808e610, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7733
            #16 0x00005559ff4ad5cf in dispatch_command (command=COM_QUERY, thd=0x7fae34000af0, packet=0x7fae34095911 "ALTER TABLE t1 ADD COLUMN extra INT", packet_length=35, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1824
            #17 0x00005559ff4ac04a in do_command (thd=0x7fae34000af0) at /data/src/10.2/sql/sql_parse.cc:1377
            #18 0x00005559ff602167 in do_handle_one_connection (connect=0x555a02a8c870) at /data/src/10.2/sql/sql_connect.cc:1336
            #19 0x00005559ff601ed2 in handle_one_connection (arg=0x555a02a8c870) at /data/src/10.2/sql/sql_connect.cc:1241
            #20 0x00005559ffe18bda in pfs_spawn_thread (arg=0x555a029d98a0) at /data/src/10.2/storage/perfschema/pfs.cc:1869
            #21 0x00007fae8f8084a4 in start_thread (arg=0x7fae8808f700) at pthread_create.c:456
            #22 0x00007fae8d93cd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
            

            Very non-deterministic test case, run with high value of --repeat (hundreds, thousands):

            --source include/have_innodb.inc
             
            CREATE TABLE t1 (a INT) ENGINE=InnoDB;
            INSERT INTO t1 VALUES (NULL);
            XA BEGIN 'x';
            UPDATE t1 SET a = 1;
            DELETE FROM t1;
             
            --connect (con1,localhost,root,,test)
            --send
              ALTER TABLE t1 ADD COLUMN extra INT;
             
            --connection default
            INSERT INTO t1 (a) VALUES (2);
            --error ER_XAER_RMFAIL
            ROLLBACK;
            DELETE FROM t1;
            INSERT INTO t1 (a) VALUES (2);
            XA END 'x';
            XA ROLLBACK 'x';
            DROP TABLE t1;
             
            --connection con1
            --error 0,ER_DUP_ENTRY
            --reap
             
            # Cleanup
            --disconnect con1
            

            I think it's related, because without the first DELETE (in line 7), the failure becomes a much easier reproducible Assertion `!log->same_pk'.

            elenst Elena Stepanova added a comment - - edited An apparently related problem: 10.2 caa474f8 mysqld: /data/src/10.2/storage/innobase/handler/handler0alter.cc:8138: bool alter_rebuild_apply_log(ha_innobase_inplace_ctx*, Alter_inplace_info*, TABLE*): Assertion `err_key < ha_alter_info->key_count' failed.   #7 0x00007fae8d87ff12 in __GI___assert_fail (assertion=0x555a000724f8 "err_key < ha_alter_info->key_count", file=0x555a0006f098 "/data/src/10.2/storage/innobase/handler/handler0alter.cc", line=8138, function=0x555a000752c0 <alter_rebuild_apply_log(ha_innobase_inplace_ctx*, Alter_inplace_info*, TABLE*)::__PRETTY_FUNCTION__> "bool alter_rebuild_apply_log(ha_innobase_inplace_ctx*, Alter_inplace_info*, TABLE*)") at assert.c:101 #8 0x00005559ff96a9ed in alter_rebuild_apply_log (ctx=0x7fae34013a28, ha_alter_info=0x7fae8808c040, altered_table=0x7fae340d25f0) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:8138 #9 0x00005559ff96b3c6 in ha_innobase::commit_inplace_alter_table (this=0x7fae380e95f8, altered_table=0x7fae340d25f0, ha_alter_info=0x7fae8808c040, commit=true) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:8316 #10 0x00005559ff735ccf in handler::ha_commit_inplace_alter_table (this=0x7fae380e95f8, altered_table=0x7fae340d25f0, ha_alter_info=0x7fae8808c040, commit=true) at /data/src/10.2/sql/handler.cc:4378 #11 0x00005559ff58506c in mysql_inplace_alter_table (thd=0x7fae34000af0, table_list=0x7fae34012698, table=0x7fae381093f0, altered_table=0x7fae340d25f0, ha_alter_info=0x7fae8808c040, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fae8808c0d0, alter_ctx=0x7fae8808c680) at /data/src/10.2/sql/sql_table.cc:7480 #12 0x00005559ff58aceb in mysql_alter_table (thd=0x7fae34000af0, new_db=0x7fae34012cb0 "test", new_name=0x0, create_info=0x7fae8808d2a0, table_list=0x7fae34012698, alter_info=0x7fae8808d1f0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9622 #13 0x00005559ff6075d0 in Sql_cmd_alter_table::execute (this=0x7fae34012da0, thd=0x7fae34000af0) at /data/src/10.2/sql/sql_alter.cc:333 #14 0x00005559ff4ba322 in mysql_execute_command (thd=0x7fae34000af0) at /data/src/10.2/sql/sql_parse.cc:5964 #15 0x00005559ff4bf2a3 in mysql_parse (thd=0x7fae34000af0, rawbuf=0x7fae340125a0 "ALTER TABLE t1 ADD COLUMN extra INT", length=35, parser_state=0x7fae8808e610, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7733 #16 0x00005559ff4ad5cf in dispatch_command (command=COM_QUERY, thd=0x7fae34000af0, packet=0x7fae34095911 "ALTER TABLE t1 ADD COLUMN extra INT", packet_length=35, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1824 #17 0x00005559ff4ac04a in do_command (thd=0x7fae34000af0) at /data/src/10.2/sql/sql_parse.cc:1377 #18 0x00005559ff602167 in do_handle_one_connection (connect=0x555a02a8c870) at /data/src/10.2/sql/sql_connect.cc:1336 #19 0x00005559ff601ed2 in handle_one_connection (arg=0x555a02a8c870) at /data/src/10.2/sql/sql_connect.cc:1241 #20 0x00005559ffe18bda in pfs_spawn_thread (arg=0x555a029d98a0) at /data/src/10.2/storage/perfschema/pfs.cc:1869 #21 0x00007fae8f8084a4 in start_thread (arg=0x7fae8808f700) at pthread_create.c:456 #22 0x00007fae8d93cd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97 Very non-deterministic test case, run with high value of --repeat (hundreds, thousands): --source include/have_innodb.inc   CREATE TABLE t1 (a INT ) ENGINE=InnoDB; INSERT INTO t1 VALUES ( NULL ); XA BEGIN 'x' ; UPDATE t1 SET a = 1; DELETE FROM t1;   --connect (con1,localhost,root,,test) --send ALTER TABLE t1 ADD COLUMN extra INT ;   --connection default INSERT INTO t1 (a) VALUES (2); --error ER_XAER_RMFAIL ROLLBACK ; DELETE FROM t1; INSERT INTO t1 (a) VALUES (2); XA END 'x' ; XA ROLLBACK 'x' ; DROP TABLE t1;   --connection con1 --error 0,ER_DUP_ENTRY --reap   # Cleanup --disconnect con1 I think it's related, because without the first DELETE (in line 7), the failure becomes a much easier reproducible Assertion `!log->same_pk' .

            There is also a curious variation of a failure on the non-debug build. I consider it a "garbage in, garbage out" situation and won't report separately, but will add it here for the record.

            Very non-deterministic test case, run with high value of --repeat (hundreds, thousands):

            --source include/have_innodb.inc
             
            CREATE TABLE t1 (a INT) ENGINE=InnoDB;
            INSERT INTO t1 VALUES (NULL);
            XA BEGIN 'x';
            UPDATE t1 SET a = 1;
             
            --connect (con1,localhost,root,,test)
            --send
              ALTER TABLE t1 ADD COLUMN extra INT;
             
            --connection default
            INSERT INTO t1 (a) VALUES (2);
            --error ER_XAER_RMFAIL
            ROLLBACK;
            DELETE FROM t1;
            INSERT INTO t1 (a) VALUES (2);
            XA END 'x';
            XA ROLLBACK 'x';
            DROP TABLE t1;
             
            --connection con1
            --error 0,ER_DUP_ENTRY
            --reap
             
            # Cleanup
            --disconnect con1
            

            10.2 5f1ec5cb non-debug

            #3  <signal handler called>
            #4  Field::is_null (row_offset=0, this=0x6) at /data/src/10.2/sql/field.h:1134
            #5  field_unpack (to=to@entry=0x7fa102f999a0, field=0x6, rec=0x7fa0b4059bf0 "\375\001", max_length=3, prefix_key=false) at /data/src/10.2/sql/key.cc:363
            #6  0x0000558d590645e5 in key_unpack (to=to@entry=0x7fa102f999a0, table=table@entry=0x7fa0b40da7b8, key=key@entry=0x7fa0b4010498) at /data/src/10.2/sql/key.cc:442
            #7  0x0000558d58fa95e5 in print_keydup_error (table=table@entry=0x7fa0b40da7b8, key=0x7fa0b4010498, msg=0x558d5964d620 "Duplicate entry '%-.64T' for key '%-.192s'", errflag=errflag@entry=0) at /data/src/10.2/sql/handler.cc:3473
            #8  0x0000558d58fa9725 in print_keydup_error (table=table@entry=0x7fa0b40da7b8, key=<optimized out>, errflag=errflag@entry=0) at /data/src/10.2/sql/handler.cc:3495
            #9  0x0000558d5913fb49 in alter_rebuild_apply_log (altered_table=0x7fa0b40da7b8, ha_alter_info=0x7fa102f9b400, ctx=0x7fa0b4010680, this=<optimized out>) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:8142
            #10 ha_innobase::commit_inplace_alter_table (this=0x7fa0b8049f50, altered_table=0x7fa0b40da7b8, ha_alter_info=0x7fa102f9b400, commit=<optimized out>) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:8316
            #11 0x0000558d58d3b6e6 in mysql_inplace_alter_table (thd=thd@entry=0x7fa0b40009a8, table_list=0x7fa0b400f2f0, table=table@entry=0x7fa0b8051be8, altered_table=altered_table@entry=0x7fa0b40da7b8, ha_alter_info=ha_alter_info@entry=0x7fa102f9b400, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, alter_ctx=0x7fa102f9bc60, target_mdl_request=0x7fa102f9b490) at /data/src/10.2/sql/sql_table.cc:7480
            #12 0x0000558d58e92231 in mysql_alter_table (thd=thd@entry=0x7fa0b40009a8, new_db=<optimized out>, new_name=<optimized out>, create_info=create_info@entry=0x7fa102f9c860, table_list=<optimized out>, table_list@entry=0x7fa0b400f2f0, alter_info=alter_info@entry=0x7fa102f9c7b0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9622
            #13 0x0000558d58ede2d4 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x7fa0b40009a8) at /data/src/10.2/sql/sql_alter.cc:333
            #14 0x0000558d58e0444a in mysql_execute_command (thd=thd@entry=0x7fa0b40009a8) at /data/src/10.2/sql/sql_parse.cc:5964
            #15 0x0000558d58e0b70e in mysql_parse (thd=thd@entry=0x7fa0b40009a8, rawbuf=<optimized out>, length=35, parser_state=parser_state@entry=0x7fa102f9e620, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.2/sql/sql_parse.cc:7733
            #16 0x0000558d58e0dfa0 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fa0b40009a8, packet=packet@entry=0x7fa0b4006d09 "ALTER TABLE t1 ADD COLUMN extra INT", packet_length=packet_length@entry=35, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.2/sql/sql_parse.cc:1824
            #17 0x0000558d58e0ed60 in do_command (thd=0x7fa0b40009a8) at /data/src/10.2/sql/sql_parse.cc:1377
            #18 0x0000558d58edb682 in do_handle_one_connection (connect=connect@entry=0x558d5b7bdec8) at /data/src/10.2/sql/sql_connect.cc:1336
            #19 0x0000558d58edb7dd in handle_one_connection (arg=arg@entry=0x558d5b7bdec8) at /data/src/10.2/sql/sql_connect.cc:1241
            #20 0x0000558d5949cf01 in pfs_spawn_thread (arg=0x558d5b755888) at /data/src/10.2/storage/perfschema/pfs.cc:1869
            #21 0x00007fa10dbd34a4 in start_thread (arg=0x7fa102f9f700) at pthread_create.c:456
            #22 0x00007fa10cc51d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
            

            elenst Elena Stepanova added a comment - There is also a curious variation of a failure on the non-debug build. I consider it a "garbage in, garbage out" situation and won't report separately, but will add it here for the record. Very non-deterministic test case, run with high value of --repeat (hundreds, thousands): --source include/have_innodb.inc   CREATE TABLE t1 (a INT ) ENGINE=InnoDB; INSERT INTO t1 VALUES ( NULL ); XA BEGIN 'x' ; UPDATE t1 SET a = 1;   --connect (con1,localhost,root,,test) --send ALTER TABLE t1 ADD COLUMN extra INT ;   --connection default INSERT INTO t1 (a) VALUES (2); --error ER_XAER_RMFAIL ROLLBACK ; DELETE FROM t1; INSERT INTO t1 (a) VALUES (2); XA END 'x' ; XA ROLLBACK 'x' ; DROP TABLE t1;   --connection con1 --error 0,ER_DUP_ENTRY --reap   # Cleanup --disconnect con1 10.2 5f1ec5cb non-debug #3 <signal handler called> #4 Field::is_null (row_offset=0, this=0x6) at /data/src/10.2/sql/field.h:1134 #5 field_unpack (to=to@entry=0x7fa102f999a0, field=0x6, rec=0x7fa0b4059bf0 "\375\001", max_length=3, prefix_key=false) at /data/src/10.2/sql/key.cc:363 #6 0x0000558d590645e5 in key_unpack (to=to@entry=0x7fa102f999a0, table=table@entry=0x7fa0b40da7b8, key=key@entry=0x7fa0b4010498) at /data/src/10.2/sql/key.cc:442 #7 0x0000558d58fa95e5 in print_keydup_error (table=table@entry=0x7fa0b40da7b8, key=0x7fa0b4010498, msg=0x558d5964d620 "Duplicate entry '%-.64T' for key '%-.192s'", errflag=errflag@entry=0) at /data/src/10.2/sql/handler.cc:3473 #8 0x0000558d58fa9725 in print_keydup_error (table=table@entry=0x7fa0b40da7b8, key=<optimized out>, errflag=errflag@entry=0) at /data/src/10.2/sql/handler.cc:3495 #9 0x0000558d5913fb49 in alter_rebuild_apply_log (altered_table=0x7fa0b40da7b8, ha_alter_info=0x7fa102f9b400, ctx=0x7fa0b4010680, this=<optimized out>) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:8142 #10 ha_innobase::commit_inplace_alter_table (this=0x7fa0b8049f50, altered_table=0x7fa0b40da7b8, ha_alter_info=0x7fa102f9b400, commit=<optimized out>) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:8316 #11 0x0000558d58d3b6e6 in mysql_inplace_alter_table (thd=thd@entry=0x7fa0b40009a8, table_list=0x7fa0b400f2f0, table=table@entry=0x7fa0b8051be8, altered_table=altered_table@entry=0x7fa0b40da7b8, ha_alter_info=ha_alter_info@entry=0x7fa102f9b400, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, alter_ctx=0x7fa102f9bc60, target_mdl_request=0x7fa102f9b490) at /data/src/10.2/sql/sql_table.cc:7480 #12 0x0000558d58e92231 in mysql_alter_table (thd=thd@entry=0x7fa0b40009a8, new_db=<optimized out>, new_name=<optimized out>, create_info=create_info@entry=0x7fa102f9c860, table_list=<optimized out>, table_list@entry=0x7fa0b400f2f0, alter_info=alter_info@entry=0x7fa102f9c7b0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9622 #13 0x0000558d58ede2d4 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x7fa0b40009a8) at /data/src/10.2/sql/sql_alter.cc:333 #14 0x0000558d58e0444a in mysql_execute_command (thd=thd@entry=0x7fa0b40009a8) at /data/src/10.2/sql/sql_parse.cc:5964 #15 0x0000558d58e0b70e in mysql_parse (thd=thd@entry=0x7fa0b40009a8, rawbuf=<optimized out>, length=35, parser_state=parser_state@entry=0x7fa102f9e620, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.2/sql/sql_parse.cc:7733 #16 0x0000558d58e0dfa0 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fa0b40009a8, packet=packet@entry=0x7fa0b4006d09 "ALTER TABLE t1 ADD COLUMN extra INT", packet_length=packet_length@entry=35, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.2/sql/sql_parse.cc:1824 #17 0x0000558d58e0ed60 in do_command (thd=0x7fa0b40009a8) at /data/src/10.2/sql/sql_parse.cc:1377 #18 0x0000558d58edb682 in do_handle_one_connection (connect=connect@entry=0x558d5b7bdec8) at /data/src/10.2/sql/sql_connect.cc:1336 #19 0x0000558d58edb7dd in handle_one_connection (arg=arg@entry=0x558d5b7bdec8) at /data/src/10.2/sql/sql_connect.cc:1241 #20 0x0000558d5949cf01 in pfs_spawn_thread (arg=0x558d5b755888) at /data/src/10.2/storage/perfschema/pfs.cc:1869 #21 0x00007fa10dbd34a4 in start_thread (arg=0x7fa102f9f700) at pthread_create.c:456 #22 0x00007fa10cc51d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
            marko Marko Mäkelä made changes -
            julien.fritsch Julien Fritsch made changes -
            Priority Major [ 3 ] Critical [ 2 ]
            wlad Vladislav Vaintroub made changes -
            Priority Critical [ 2 ] Major [ 3 ]
            wlad Vladislav Vaintroub made changes -
            Roel Roel Van de Paar made changes -

            Please check MDEV-24225 (uses the SQL from one of the testcases in a new way) if it is related.

            Roel Roel Van de Paar added a comment - Please check MDEV-24225 (uses the SQL from one of the testcases in a new way) if it is related.
            monty Michael Widenius made changes -
            Assignee Vladislav Vaintroub [ wlad ] Michael Widenius [ monty ]
            monty Michael Widenius made changes -
            Status Confirmed [ 10101 ] In Progress [ 3 ]

            The reason for the failure is that thd->mdl_context.release_transactional_locks() was called after commit & rollback even in cases where the current transaction is still active.
            I have now created a fix, it's now tested by buildbot in bb-10.2-monty and in review by Serg

            monty Michael Widenius added a comment - The reason for the failure is that thd->mdl_context.release_transactional_locks() was called after commit & rollback even in cases where the current transaction is still active. I have now created a fix, it's now tested by buildbot in bb-10.2-monty and in review by Serg

            Please take a look at 2aae278aadae191cfee930a69a2ec00af9606ec4

            monty Michael Widenius added a comment - Please take a look at 2aae278aadae191cfee930a69a2ec00af9606ec4
            monty Michael Widenius made changes -
            Assignee Michael Widenius [ monty ] Sergei Golubchik [ serg ]
            Status In Progress [ 3 ] In Review [ 10002 ]

            The reason for the failure is that thd->mdl_context.release_transactional_locks()
            was called after commit & rollback even in cases where the current transaction is still active.

            For 10.2, 10.3 and 10.4 the fix is simple:

            • Replace all calls to thd->mdl_context.release_transactional_locks() with
              thd->release_transactional_locks(). The thd function will only call
              the mdl_context function if there are no active transactional locks.
              In 10.6 we will better fix where we will change the return value for
              some trans_xxx() functions to indicate if transaction did close the
              transaction or not. This will avoid the need of the indirect call.

            In addition I have pushed a related fix in 10.4 to avoid a problem with the trans_xa_detach()

            monty Michael Widenius added a comment - The reason for the failure is that thd->mdl_context.release_transactional_locks() was called after commit & rollback even in cases where the current transaction is still active. For 10.2, 10.3 and 10.4 the fix is simple: Replace all calls to thd->mdl_context.release_transactional_locks() with thd->release_transactional_locks(). The thd function will only call the mdl_context function if there are no active transactional locks. In 10.6 we will better fix where we will change the return value for some trans_xxx() functions to indicate if transaction did close the transaction or not. This will avoid the need of the indirect call. In addition I have pushed a related fix in 10.4 to avoid a problem with the trans_xa_detach()
            monty Michael Widenius made changes -
            issue.field.resolutiondate 2020-12-01 00:59:57.0 2020-12-01 00:59:57.323
            monty Michael Widenius made changes -
            Component/s Locking [ 10900 ]
            Fix Version/s 10.2.37 [ 25112 ]
            Fix Version/s 10.3.28 [ 25111 ]
            Fix Version/s 10.4.18 [ 25110 ]
            Fix Version/s 10.5.9 [ 25109 ]
            Fix Version/s 10.2 [ 14601 ]
            Assignee Sergei Golubchik [ serg ] Allen Lee [ allen.lee@mariadb.com ]
            Resolution Fixed [ 1 ]
            Status In Review [ 10002 ] Closed [ 6 ]
            monty Michael Widenius made changes -
            Assignee Allen Lee [ allen.lee@mariadb.com ] Michael Widenius [ monty ]
            monty Michael Widenius made changes -
            serg Sergei Golubchik made changes -
            Workflow MariaDB v3 [ 85955 ] MariaDB v4 [ 153933 ]

            People

              monty Michael Widenius
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              9 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.