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

ALTER INPLACE running TOI doesn't abort a DML operation in InnoDB

Details

    Description

      The test ported from MDEV-32738 hangs as ALTER INPLACE is unable to abort a DML INSERT operation:

      --connect con1_1,127.0.0.1,root,,test,$NODE_MYPORT_1
      --connect con1_2,127.0.0.1,root,,test,$NODE_MYPORT_1
       
      CREATE TABLE t1(c1 INT PRIMARY KEY) ENGINE=InnoDB;
      CREATE TABLE t1_fk(c1 INT PRIMARY KEY, c2 INT, INDEX (c2), FOREIGN KEY (c2) REFERENCES t1(c1)) ENGINE=InnoDB;
       
      INSERT INTO t1 VALUES (1);
       
      --connection con1_1
      SET DEBUG_SYNC = 'ib_after_row_insert WAIT_FOR bf_abort';
      # INSERT also grabs FK-referenced table lock.
      --send
        INSERT INTO t1_fk VALUES (1, 1);
       
      --connection con1_2
      SET DEBUG_SYNC = 'ha_write_row_start SIGNAL may_alter WAIT_FOR may_insert';
      # Stop before doing anything, but pass wsrep_sync_wait().
      # This should be done before ALTER enters TOI.
      --send
        INSERT INTO t1_fk VALUES (2, 2);
       
      --connection node_1
      SET DEBUG_SYNC = 'now WAIT_FOR may_alter';
      SET DEBUG_SYNC = 'lock_wait_before_suspend SIGNAL may_insert WAIT_FOR alter_continue';
      # ALTER BF-aborts the first INSERT and lets the second INSERT continue.
      --send
        ALTER TABLE t1 ADD COLUMN c2 INT;
       
      --connection con1_1
      # First INSERT gets BF-aborted.
      --error ER_LOCK_DEADLOCK
      --reap
       
      --connection con1_2
      # Second INSERT rolls back as ALTER is waiting on the lock.
      --error ER_LOCK_DEADLOCK
      --reap
      SET DEBUG_SYNC = 'now SIGNAL alter_continue';
       
      --connection node_1
      # ALTER succeeds.
      --reap
      

      The reason is that ALTER's InnoDB trx has is_wsrep() == false. That might be because trx initialization has been moved to the ctor of ha_innobase_inplace_ctx() which is now done earlier in prepare_inplace_alter_table().

      Attachments

        Issue Links

          Activity

            I was asked to review this. Can you post stack traces of the relevant threads that illustrate the problem?

            marko Marko Mäkelä added a comment - I was asked to review this. Can you post stack traces of the relevant threads that illustrate the problem?
            denis.protivensky Denis Protivensky added a comment - - edited

            Here are the two threads of interest:

            Thread 7 (Thread 0x7f45e56ff700 (LWP 67019)):
            #0  futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7f45e56f9bf0, clockid=<optimized out>, expected=0, futex_word=0x5595e7301b1c) at ../sysdeps/nptl/futex-internal.h:320
            #1  __pthread_cond_wait_common (abstime=0x7f45e56f9bf0, clockid=<optimized out>, mutex=0x5595e7301b50, cond=0x5595e7301af0) at pthread_cond_wait.c:520
            #2  __pthread_cond_timedwait (cond=0x5595e7301af0, mutex=0x5595e7301b50, abstime=0x7f45e56f9bf0) at pthread_cond_wait.c:665
            #3  0x00005595e4be730c in safe_cond_timedwait (cond=0x5595e7301af0, mp=0x5595e7301b28, abstime=0x7f45e56f9bf0, file=0x5595e51d09a0 "/home/denis/dev/mariadb-server-features/mysys/my_thr_init.c", line=609) at /home/denis/dev/mariadb-server-features/mysys/thr_mutex.c:546
            #4  0x00005595e4be02a1 in psi_cond_timedwait (that=0x5595e7301af0, mutex=0x5595e7301b28, abstime=0x7f45e56f9bf0, file=0x5595e4d28a28 "/home/denis/dev/mariadb-server-features/sql/debug_sync.cc", line=1671) at /home/denis/dev/mariadb-server-features/mysys/my_thr_init.c:609
            #5  0x00005595e3f2cbd6 in inline_mysql_cond_timedwait (that=0x5595e7301af0, mutex=0x5595e7301b28, abstime=0x7f45e56f9bf0, src_file=0x5595e4d28a28 "/home/denis/dev/mariadb-server-features/sql/debug_sync.cc", src_line=1671) at /home/denis/dev/mariadb-server-features/include/mysql/psi/mysql_thread.h:1086
            #6  0x00005595e3f30cf6 in debug_sync_execute (thd=0x7f45b0001138, action=0x7f45b0036aa8) at /home/denis/dev/mariadb-server-features/sql/debug_sync.cc:1669
            #7  0x00005595e3f313a9 in debug_sync (thd=0x7f45b0001138, sync_point_name=0x5595e5097510 "lock_wait_end", name_len=13) at /home/denis/dev/mariadb-server-features/sql/debug_sync.cc:1781
            #8  0x00005595e47da6c6 in <lambda()>::operator()(void) const (__closure=0x7f45e56f9d60) at /home/denis/dev/mariadb-server-features/storage/innobase/lock/lock0lock.cc:1865
            #9  0x00005595e47edbe6 in detail::scope_exit<lock_wait(que_thr_t*)::<lambda()> >::~scope_exit(void) (this=0x7f45e56f9d60, __in_chrg=<optimized out>) at /home/denis/dev/mariadb-server-features/include/scope.h:50
            #10 0x00005595e47db044 in lock_wait (thr=0x7f45b0039e58) at /home/denis/dev/mariadb-server-features/storage/innobase/lock/lock0lock.cc:1866
            #11 0x00005595e48f180d in row_mysql_handle_errors (new_err=0x7f45e56f9fd4, trx=0x7f45e6999c80, thr=0x7f45b0039e58, savept=0x0) at /home/denis/dev/mariadb-server-features/storage/innobase/row/row0mysql.cc:688
            #12 0x00005595e47e258a in lock_table_for_trx (table=0x7f45a8022f08, trx=0x7f45e6999c80, mode=LOCK_X, no_wait=false) at /home/denis/dev/mariadb-server-features/storage/innobase/lock/lock0lock.cc:3965
            #13 0x00005595e47e2919 in lock_table_children (table=0x7f45a80236e8, trx=0x7f45e6999c80) at /home/denis/dev/mariadb-server-features/storage/innobase/lock/lock0lock.cc:4018
            #14 0x00005595e477e3c8 in ha_innobase::commit_inplace_alter_table (this=0x7f45a8027e90, altered_table=0x7f45e56fade0, ha_alter_info=0x7f45e56fad20, commit=true) at /home/denis/dev/mariadb-server-features/storage/innobase/handler/handler0alter.cc:11210
            #15 0x00005595e42b4f40 in handler::ha_commit_inplace_alter_table (this=0x7f45a8027e90, altered_table=0x7f45e56fade0, ha_alter_info=0x7f45e56fad20, commit=true) at /home/denis/dev/mariadb-server-features/sql/handler.cc:5314
            #16 0x00005595e40039a2 in mysql_inplace_alter_table (thd=0x7f45b0001138, table_list=0x7f45b00144f0, table=0x7f45a802e068, altered_table=0x7f45e56fade0, ha_alter_info=0x7f45e56fad20, target_mdl_request=0x7f45e56fb6a0, ddl_log_state=0x7f45e56facc0, trigger_param=0x7f45e56fb210, alter_ctx=0x7f45e56fc260) at /home/denis/dev/mariadb-server-features/sql/sql_table.cc:7590
            #17 0x00005595e400cf20 in mysql_alter_table (thd=0x7f45b0001138, new_db=0x7f45b0005dc8, new_name=0x7f45b0006230, create_info=0x7f45e56fd100, table_list=0x7f45b00144f0, recreate_info=0x7f45e56fcf50, alter_info=0x7f45e56fcf90, order_num=0, order=0x0, ignore=false, if_exists=false) at /home/denis/dev/mariadb-server-features/sql/sql_table.cc:10566
            #18 0x00005595e40c809c in Sql_cmd_alter_table::execute (this=0x7f45b0014d20, thd=0x7f45b0001138) at /home/denis/dev/mariadb-server-features/sql/sql_alter.cc:675
            #19 0x00005595e3efe060 in mysql_execute_command (thd=0x7f45b0001138, is_called_from_prepared_stmt=false) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:6117
            #20 0x00005595e3f041a8 in mysql_parse (thd=0x7f45b0001138, rawbuf=0x7f45b00143e0 "ALTER TABLE t1 ADD COLUMN c2 INT, ALGORITHM=INPLACE", length=51, parser_state=0x7f45e56fe2e0) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:8139
            #21 0x00005595e3f03880 in wsrep_mysql_parse (thd=0x7f45b0001138, rawbuf=0x7f45b00143e0 "ALTER TABLE t1 ADD COLUMN c2 INT, ALGORITHM=INPLACE", length=51, parser_state=0x7f45e56fe2e0) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:7950
            #22 0x00005595e3eeff94 in dispatch_command (command=COM_QUERY, thd=0x7f45b0001138, packet=0x7f45b000ba39 "ALTER TABLE t1 ADD COLUMN c2 INT, ALGORITHM=INPLACE", packet_length=51, blocking=true) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:1883
            #23 0x00005595e3eee950 in do_command (thd=0x7f45b0001138, blocking=true) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:1409
            #24 0x00005595e40bc1f5 in do_handle_one_connection (connect=0x5595e7a51e18, put_in_cache=true) at /home/denis/dev/mariadb-server-features/sql/sql_connect.cc:1415
            #25 0x00005595e40bbf4b in handle_one_connection (arg=0x5595e7a51e18) at /home/denis/dev/mariadb-server-features/sql/sql_connect.cc:1317
            #26 0x00005595e4641fef in pfs_spawn_thread (arg=0x5595e7350768) at /home/denis/dev/mariadb-server-features/storage/perfschema/pfs.cc:2201
            #27 0x00007f4604e20609 in start_thread (arg=<optimized out>) at pthread_create.c:477
            #28 0x00007f46049f1353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
             
            Thread 3 (Thread 0x7f45e56b4700 (LWP 67020)):
            #0  futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7f45e56b24d0, clockid=<optimized out>, expected=0, futex_word=0x5595e7301b1c) at ../sysdeps/nptl/futex-internal.h:320
            #1  __pthread_cond_wait_common (abstime=0x7f45e56b24d0, clockid=<optimized out>, mutex=0x5595e7301b50, cond=0x5595e7301af0) at pthread_cond_wait.c:520
            #2  __pthread_cond_timedwait (cond=0x5595e7301af0, mutex=0x5595e7301b50, abstime=0x7f45e56b24d0) at pthread_cond_wait.c:665                                                                     #3  0x00005595e4be730c in safe_cond_timedwait (cond=0x5595e7301af0, mp=0x5595e7301b28, abstime=0x7f45e56b24d0, file=0x5595e51d09a0 "/home/denis/dev/mariadb-server-features/mysys/my_thr_init.c", line=609) at /home/denis/dev/mariadb-server-features/mysys/thr_mutex.c:546                                                                                                                    #4  0x00005595e4be02a1 in psi_cond_timedwait (that=0x5595e7301af0, mutex=0x5595e7301b28, abstime=0x7f45e56b24d0, file=0x5595e4d28a28 "/home/denis/dev/mariadb-server-features/sql/debug_sync.cc", line=1671) at /home/denis/dev/mariadb-server-features/mysys/my_thr_init.c:609                                                                                                                 #5  0x00005595e3f2cbd6 in inline_mysql_cond_timedwait (that=0x5595e7301af0, mutex=0x5595e7301b28, abstime=0x7f45e56b24d0, src_file=0x5595e4d28a28 "/home/denis/dev/mariadb-server-features/sql/debug_sync.cc", src_line=1671) at /home/denis/dev/mariadb-server-features/include/mysql/psi/mysql_thread.h:1086
            #6  0x00005595e3f30cf6 in debug_sync_execute (thd=0x7f45a8000db8, action=0x7f45a8951c28) at /home/denis/dev/mariadb-server-features/sql/debug_sync.cc:1669
            #7  0x00005595e3f313a9 in debug_sync (thd=0x7f45a8000db8, sync_point_name=0x5595e506c802 "ib_after_row_insert", name_len=19) at /home/denis/dev/mariadb-server-features/sql/debug_sync.cc:1781
            #8  0x00005595e472836b in ha_innobase::write_row (this=0x7f45a8957de0, record=0x7f45a8955198 "\375\001") at /home/denis/dev/mariadb-server-features/storage/innobase/handler/ha_innodb.cc:7846
            #9  0x00005595e42bc5c2 in handler::ha_write_row (this=0x7f45a8957de0, buf=0x7f45a8955198 "\375\001") at /home/denis/dev/mariadb-server-features/sql/handler.cc:7685
            #10 0x00005595e3ea4f28 in write_record (thd=0x7f45a8000db8, table=0x7f45a89578f8, info=0x7f45e56b2910, sink=0x0) at /home/denis/dev/mariadb-server-features/sql/sql_insert.cc:2187
            #11 0x00005595e3ea19e1 in mysql_insert (thd=0x7f45a8000db8, table_list=0x7f45a8019d90, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false, result=0x0) at /home/denis/dev/mariadb-server-features/sql/sql_insert.cc:1133
            #12 0x00005595e3ef834d in mysql_execute_command (thd=0x7f45a8000db8, is_called_from_prepared_stmt=false) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:4601
            #13 0x00005595e3f041a8 in mysql_parse (thd=0x7f45a8000db8, rawbuf=0x7f45a8019cb0 "INSERT INTO t1_fk VALUES (1, 1)", length=31, parser_state=0x7f45e56b32e0) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:8139
            #14 0x00005595e3f03880 in wsrep_mysql_parse (thd=0x7f45a8000db8, rawbuf=0x7f45a8019cb0 "INSERT INTO t1_fk VALUES (1, 1)", length=31, parser_state=0x7f45e56b32e0) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:7950
            #15 0x00005595e3eeff94 in dispatch_command (command=COM_QUERY, thd=0x7f45a8000db8, packet=0x7f45a8011b59 "INSERT INTO t1_fk VALUES (1, 1)", packet_length=31, blocking=true) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:1883
            #16 0x00005595e3eee950 in do_command (thd=0x7f45a8000db8, blocking=true) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:1409
            #17 0x00005595e40bc1f5 in do_handle_one_connection (connect=0x5595e7a5c328, put_in_cache=true) at /home/denis/dev/mariadb-server-features/sql/sql_connect.cc:1415
            #18 0x00005595e40bbf4b in handle_one_connection (arg=0x5595e7a5c328) at /home/denis/dev/mariadb-server-features/sql/sql_connect.cc:1317
            #19 0x00005595e4641fef in pfs_spawn_thread (arg=0x5595e79d55d8) at /home/denis/dev/mariadb-server-features/storage/perfschema/pfs.cc:2201
            #20 0x00007f4604e20609 in start_thread (arg=<optimized out>) at pthread_create.c:477
            #21 0x00007f46049f1353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
            

            Thread 7 (ALTER) didn't run BF-abort checks in lock_table_for_trx() - > lock_table() - > lock_table_wsrep() because the last method was not called due to trx->is_wsrep() == false.

            denis.protivensky Denis Protivensky added a comment - - edited Here are the two threads of interest: Thread 7 (Thread 0x7f45e56ff700 (LWP 67019)): #0 futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7f45e56f9bf0, clockid=<optimized out>, expected=0, futex_word=0x5595e7301b1c) at ../sysdeps/nptl/futex-internal.h:320 #1 __pthread_cond_wait_common (abstime=0x7f45e56f9bf0, clockid=<optimized out>, mutex=0x5595e7301b50, cond=0x5595e7301af0) at pthread_cond_wait.c:520 #2 __pthread_cond_timedwait (cond=0x5595e7301af0, mutex=0x5595e7301b50, abstime=0x7f45e56f9bf0) at pthread_cond_wait.c:665 #3 0x00005595e4be730c in safe_cond_timedwait (cond=0x5595e7301af0, mp=0x5595e7301b28, abstime=0x7f45e56f9bf0, file=0x5595e51d09a0 "/home/denis/dev/mariadb-server-features/mysys/my_thr_init.c", line=609) at /home/denis/dev/mariadb-server-features/mysys/thr_mutex.c:546 #4 0x00005595e4be02a1 in psi_cond_timedwait (that=0x5595e7301af0, mutex=0x5595e7301b28, abstime=0x7f45e56f9bf0, file=0x5595e4d28a28 "/home/denis/dev/mariadb-server-features/sql/debug_sync.cc", line=1671) at /home/denis/dev/mariadb-server-features/mysys/my_thr_init.c:609 #5 0x00005595e3f2cbd6 in inline_mysql_cond_timedwait (that=0x5595e7301af0, mutex=0x5595e7301b28, abstime=0x7f45e56f9bf0, src_file=0x5595e4d28a28 "/home/denis/dev/mariadb-server-features/sql/debug_sync.cc", src_line=1671) at /home/denis/dev/mariadb-server-features/include/mysql/psi/mysql_thread.h:1086 #6 0x00005595e3f30cf6 in debug_sync_execute (thd=0x7f45b0001138, action=0x7f45b0036aa8) at /home/denis/dev/mariadb-server-features/sql/debug_sync.cc:1669 #7 0x00005595e3f313a9 in debug_sync (thd=0x7f45b0001138, sync_point_name=0x5595e5097510 "lock_wait_end", name_len=13) at /home/denis/dev/mariadb-server-features/sql/debug_sync.cc:1781 #8 0x00005595e47da6c6 in <lambda()>::operator()(void) const (__closure=0x7f45e56f9d60) at /home/denis/dev/mariadb-server-features/storage/innobase/lock/lock0lock.cc:1865 #9 0x00005595e47edbe6 in detail::scope_exit<lock_wait(que_thr_t*)::<lambda()> >::~scope_exit(void) (this=0x7f45e56f9d60, __in_chrg=<optimized out>) at /home/denis/dev/mariadb-server-features/include/scope.h:50 #10 0x00005595e47db044 in lock_wait (thr=0x7f45b0039e58) at /home/denis/dev/mariadb-server-features/storage/innobase/lock/lock0lock.cc:1866 #11 0x00005595e48f180d in row_mysql_handle_errors (new_err=0x7f45e56f9fd4, trx=0x7f45e6999c80, thr=0x7f45b0039e58, savept=0x0) at /home/denis/dev/mariadb-server-features/storage/innobase/row/row0mysql.cc:688 #12 0x00005595e47e258a in lock_table_for_trx (table=0x7f45a8022f08, trx=0x7f45e6999c80, mode=LOCK_X, no_wait=false) at /home/denis/dev/mariadb-server-features/storage/innobase/lock/lock0lock.cc:3965 #13 0x00005595e47e2919 in lock_table_children (table=0x7f45a80236e8, trx=0x7f45e6999c80) at /home/denis/dev/mariadb-server-features/storage/innobase/lock/lock0lock.cc:4018 #14 0x00005595e477e3c8 in ha_innobase::commit_inplace_alter_table (this=0x7f45a8027e90, altered_table=0x7f45e56fade0, ha_alter_info=0x7f45e56fad20, commit=true) at /home/denis/dev/mariadb-server-features/storage/innobase/handler/handler0alter.cc:11210 #15 0x00005595e42b4f40 in handler::ha_commit_inplace_alter_table (this=0x7f45a8027e90, altered_table=0x7f45e56fade0, ha_alter_info=0x7f45e56fad20, commit=true) at /home/denis/dev/mariadb-server-features/sql/handler.cc:5314 #16 0x00005595e40039a2 in mysql_inplace_alter_table (thd=0x7f45b0001138, table_list=0x7f45b00144f0, table=0x7f45a802e068, altered_table=0x7f45e56fade0, ha_alter_info=0x7f45e56fad20, target_mdl_request=0x7f45e56fb6a0, ddl_log_state=0x7f45e56facc0, trigger_param=0x7f45e56fb210, alter_ctx=0x7f45e56fc260) at /home/denis/dev/mariadb-server-features/sql/sql_table.cc:7590 #17 0x00005595e400cf20 in mysql_alter_table (thd=0x7f45b0001138, new_db=0x7f45b0005dc8, new_name=0x7f45b0006230, create_info=0x7f45e56fd100, table_list=0x7f45b00144f0, recreate_info=0x7f45e56fcf50, alter_info=0x7f45e56fcf90, order_num=0, order=0x0, ignore=false, if_exists=false) at /home/denis/dev/mariadb-server-features/sql/sql_table.cc:10566 #18 0x00005595e40c809c in Sql_cmd_alter_table::execute (this=0x7f45b0014d20, thd=0x7f45b0001138) at /home/denis/dev/mariadb-server-features/sql/sql_alter.cc:675 #19 0x00005595e3efe060 in mysql_execute_command (thd=0x7f45b0001138, is_called_from_prepared_stmt=false) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:6117 #20 0x00005595e3f041a8 in mysql_parse (thd=0x7f45b0001138, rawbuf=0x7f45b00143e0 "ALTER TABLE t1 ADD COLUMN c2 INT, ALGORITHM=INPLACE", length=51, parser_state=0x7f45e56fe2e0) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:8139 #21 0x00005595e3f03880 in wsrep_mysql_parse (thd=0x7f45b0001138, rawbuf=0x7f45b00143e0 "ALTER TABLE t1 ADD COLUMN c2 INT, ALGORITHM=INPLACE", length=51, parser_state=0x7f45e56fe2e0) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:7950 #22 0x00005595e3eeff94 in dispatch_command (command=COM_QUERY, thd=0x7f45b0001138, packet=0x7f45b000ba39 "ALTER TABLE t1 ADD COLUMN c2 INT, ALGORITHM=INPLACE", packet_length=51, blocking=true) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:1883 #23 0x00005595e3eee950 in do_command (thd=0x7f45b0001138, blocking=true) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:1409 #24 0x00005595e40bc1f5 in do_handle_one_connection (connect=0x5595e7a51e18, put_in_cache=true) at /home/denis/dev/mariadb-server-features/sql/sql_connect.cc:1415 #25 0x00005595e40bbf4b in handle_one_connection (arg=0x5595e7a51e18) at /home/denis/dev/mariadb-server-features/sql/sql_connect.cc:1317 #26 0x00005595e4641fef in pfs_spawn_thread (arg=0x5595e7350768) at /home/denis/dev/mariadb-server-features/storage/perfschema/pfs.cc:2201 #27 0x00007f4604e20609 in start_thread (arg=<optimized out>) at pthread_create.c:477 #28 0x00007f46049f1353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95   Thread 3 (Thread 0x7f45e56b4700 (LWP 67020)): #0 futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7f45e56b24d0, clockid=<optimized out>, expected=0, futex_word=0x5595e7301b1c) at ../sysdeps/nptl/futex-internal.h:320 #1 __pthread_cond_wait_common (abstime=0x7f45e56b24d0, clockid=<optimized out>, mutex=0x5595e7301b50, cond=0x5595e7301af0) at pthread_cond_wait.c:520 #2 __pthread_cond_timedwait (cond=0x5595e7301af0, mutex=0x5595e7301b50, abstime=0x7f45e56b24d0) at pthread_cond_wait.c:665 #3 0x00005595e4be730c in safe_cond_timedwait (cond=0x5595e7301af0, mp=0x5595e7301b28, abstime=0x7f45e56b24d0, file=0x5595e51d09a0 "/home/denis/dev/mariadb-server-features/mysys/my_thr_init.c", line=609) at /home/denis/dev/mariadb-server-features/mysys/thr_mutex.c:546 #4 0x00005595e4be02a1 in psi_cond_timedwait (that=0x5595e7301af0, mutex=0x5595e7301b28, abstime=0x7f45e56b24d0, file=0x5595e4d28a28 "/home/denis/dev/mariadb-server-features/sql/debug_sync.cc", line=1671) at /home/denis/dev/mariadb-server-features/mysys/my_thr_init.c:609 #5 0x00005595e3f2cbd6 in inline_mysql_cond_timedwait (that=0x5595e7301af0, mutex=0x5595e7301b28, abstime=0x7f45e56b24d0, src_file=0x5595e4d28a28 "/home/denis/dev/mariadb-server-features/sql/debug_sync.cc", src_line=1671) at /home/denis/dev/mariadb-server-features/include/mysql/psi/mysql_thread.h:1086 #6 0x00005595e3f30cf6 in debug_sync_execute (thd=0x7f45a8000db8, action=0x7f45a8951c28) at /home/denis/dev/mariadb-server-features/sql/debug_sync.cc:1669 #7 0x00005595e3f313a9 in debug_sync (thd=0x7f45a8000db8, sync_point_name=0x5595e506c802 "ib_after_row_insert", name_len=19) at /home/denis/dev/mariadb-server-features/sql/debug_sync.cc:1781 #8 0x00005595e472836b in ha_innobase::write_row (this=0x7f45a8957de0, record=0x7f45a8955198 "\375\001") at /home/denis/dev/mariadb-server-features/storage/innobase/handler/ha_innodb.cc:7846 #9 0x00005595e42bc5c2 in handler::ha_write_row (this=0x7f45a8957de0, buf=0x7f45a8955198 "\375\001") at /home/denis/dev/mariadb-server-features/sql/handler.cc:7685 #10 0x00005595e3ea4f28 in write_record (thd=0x7f45a8000db8, table=0x7f45a89578f8, info=0x7f45e56b2910, sink=0x0) at /home/denis/dev/mariadb-server-features/sql/sql_insert.cc:2187 #11 0x00005595e3ea19e1 in mysql_insert (thd=0x7f45a8000db8, table_list=0x7f45a8019d90, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false, result=0x0) at /home/denis/dev/mariadb-server-features/sql/sql_insert.cc:1133 #12 0x00005595e3ef834d in mysql_execute_command (thd=0x7f45a8000db8, is_called_from_prepared_stmt=false) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:4601 #13 0x00005595e3f041a8 in mysql_parse (thd=0x7f45a8000db8, rawbuf=0x7f45a8019cb0 "INSERT INTO t1_fk VALUES (1, 1)", length=31, parser_state=0x7f45e56b32e0) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:8139 #14 0x00005595e3f03880 in wsrep_mysql_parse (thd=0x7f45a8000db8, rawbuf=0x7f45a8019cb0 "INSERT INTO t1_fk VALUES (1, 1)", length=31, parser_state=0x7f45e56b32e0) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:7950 #15 0x00005595e3eeff94 in dispatch_command (command=COM_QUERY, thd=0x7f45a8000db8, packet=0x7f45a8011b59 "INSERT INTO t1_fk VALUES (1, 1)", packet_length=31, blocking=true) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:1883 #16 0x00005595e3eee950 in do_command (thd=0x7f45a8000db8, blocking=true) at /home/denis/dev/mariadb-server-features/sql/sql_parse.cc:1409 #17 0x00005595e40bc1f5 in do_handle_one_connection (connect=0x5595e7a5c328, put_in_cache=true) at /home/denis/dev/mariadb-server-features/sql/sql_connect.cc:1415 #18 0x00005595e40bbf4b in handle_one_connection (arg=0x5595e7a5c328) at /home/denis/dev/mariadb-server-features/sql/sql_connect.cc:1317 #19 0x00005595e4641fef in pfs_spawn_thread (arg=0x5595e79d55d8) at /home/denis/dev/mariadb-server-features/storage/perfschema/pfs.cc:2201 #20 0x00007f4604e20609 in start_thread (arg=<optimized out>) at pthread_create.c:477 #21 0x00007f46049f1353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 Thread 7 (ALTER) didn't run BF-abort checks in lock_table_for_trx() - > lock_table() - > lock_table_wsrep() because the last method was not called due to trx->is_wsrep() == false.

            I see that the transaction was started in prepare_inplace_alter_table_dict().

            marko Marko Mäkelä added a comment - I see that the transaction was started in prepare_inplace_alter_table_dict() .

            I understand that we would want to move the assignment from innobase_trx_init() to trx_start_low() and not duplicate it. I debugged why the added assertion in trx_t::commit_in_memory() would fail if the assignment is removed from innobase_trx_init(). It turns out that Wsrep_schema::store_view() would set the flag thd->variables.wsrep_on after the transaction had already been started, and then this change would be applied to trx->wsrep right before the transaction is being committed:

            #0  innobase_trx_init (thd=thd@entry=0x7ff1a8000d58, trx=trx@entry=0x7ff1c1c00b80) at /mariadb/10.6m/storage/innobase/handler/ha_innodb.cc:2876
            #1  0x00005583ea956e9c in check_trx_exists (thd=thd@entry=0x7ff1a8000d58) at /mariadb/10.6m/storage/innobase/handler/ha_innodb.cc:2932
            #2  0x00005583ea9583f2 in innobase_commit (hton=<optimized out>, thd=0x7ff1a8000d58, commit_trx=true) at /mariadb/10.6m/storage/innobase/handler/ha_innodb.cc:4571
            #3  0x00005583ea44b27e in commit_one_phase_2 (thd=thd@entry=0x7ff1a8000d58, all=all@entry=true, trans=trans@entry=0x7ff1a8004710, is_real_trans=true) at /mariadb/10.6m/sql/handler.cc:2109
            #4  0x00005583ea44b3af in ha_commit_one_phase (thd=thd@entry=0x7ff1a8000d58, all=all@entry=true) at /mariadb/10.6m/sql/handler.cc:2062
            #5  0x00005583ea44c193 in ha_commit_trans (thd=thd@entry=0x7ff1a8000d58, all=all@entry=true) at /mariadb/10.6m/sql/handler.cc:1856
            #6  0x00005583ea7895a5 in trans_commit (thd=0x7ff1a8000d58) at /mariadb/10.6m/sql/transaction.cc:270
            #7  0x00005583ea9337bc in Wsrep_server_service::log_view (this=<optimized out>, high_priority_service=0x7ff1ce4a3a90, 
                view=@0x7ff1ce4a2a30: {state_id_ = {id_ = {data_ = {buf = "\327m\355[\353f\021\356\2210Re\217\263\0179"}}, seqno_ = {seqno_ = 1}}, view_seqno_ = {seqno_ = 1}, status_ = wsrep::view::primary, capabilities_ = 184703, own_index_ = 0, protocol_version_ = 4, members_ = std::vector of length 1, capacity 1 = {{id_ = {data_ = {buf = "\327l\265\303\353f\021\356\207Xo\006\203\035", <incomplete sequence \373>}}, name_ = "jyty", incoming_ = "127.0.0.1:16000"}}}) at /mariadb/10.6m/sql/wsrep_server_service.cc:259
            

            I was under the impression that the "wsrep-ness" of an active transaction is not supposed to change. I think that this needs to be clarified.

            marko Marko Mäkelä added a comment - I understand that we would want to move the assignment from innobase_trx_init() to trx_start_low() and not duplicate it. I debugged why the added assertion in trx_t::commit_in_memory() would fail if the assignment is removed from innobase_trx_init() . It turns out that Wsrep_schema::store_view() would set the flag thd->variables.wsrep_on after the transaction had already been started, and then this change would be applied to trx->wsrep right before the transaction is being committed: #0 innobase_trx_init (thd=thd@entry=0x7ff1a8000d58, trx=trx@entry=0x7ff1c1c00b80) at /mariadb/10.6m/storage/innobase/handler/ha_innodb.cc:2876 #1 0x00005583ea956e9c in check_trx_exists (thd=thd@entry=0x7ff1a8000d58) at /mariadb/10.6m/storage/innobase/handler/ha_innodb.cc:2932 #2 0x00005583ea9583f2 in innobase_commit (hton=<optimized out>, thd=0x7ff1a8000d58, commit_trx=true) at /mariadb/10.6m/storage/innobase/handler/ha_innodb.cc:4571 #3 0x00005583ea44b27e in commit_one_phase_2 (thd=thd@entry=0x7ff1a8000d58, all=all@entry=true, trans=trans@entry=0x7ff1a8004710, is_real_trans=true) at /mariadb/10.6m/sql/handler.cc:2109 #4 0x00005583ea44b3af in ha_commit_one_phase (thd=thd@entry=0x7ff1a8000d58, all=all@entry=true) at /mariadb/10.6m/sql/handler.cc:2062 #5 0x00005583ea44c193 in ha_commit_trans (thd=thd@entry=0x7ff1a8000d58, all=all@entry=true) at /mariadb/10.6m/sql/handler.cc:1856 #6 0x00005583ea7895a5 in trans_commit (thd=0x7ff1a8000d58) at /mariadb/10.6m/sql/transaction.cc:270 #7 0x00005583ea9337bc in Wsrep_server_service::log_view (this=<optimized out>, high_priority_service=0x7ff1ce4a3a90, view=@0x7ff1ce4a2a30: {state_id_ = {id_ = {data_ = {buf = "\327m\355[\353f\021\356\2210Re\217\263\0179"}}, seqno_ = {seqno_ = 1}}, view_seqno_ = {seqno_ = 1}, status_ = wsrep::view::primary, capabilities_ = 184703, own_index_ = 0, protocol_version_ = 4, members_ = std::vector of length 1, capacity 1 = {{id_ = {data_ = {buf = "\327l\265\303\353f\021\356\207Xo\006\203\035", <incomplete sequence \373>}}, name_ = "jyty", incoming_ = "127.0.0.1:16000"}}}) at /mariadb/10.6m/sql/wsrep_server_service.cc:259 I was under the impression that the "wsrep-ness" of an active transaction is not supposed to change. I think that this needs to be clarified.

            I agree that it's better to have a single place where trx->wsrep is handled. I will have to investigate the issue a bit more then.

            denis.protivensky Denis Protivensky added a comment - I agree that it's better to have a single place where trx->wsrep is handled. I will have to investigate the issue a bit more then.
            sysprg Julius Goryavsky added a comment - Fixes are merged with head revision as https://github.com/MariaDB/server/commit/cfbd57dfb7920ed9858d3d12f74f0ba4b6f60c36 and https://github.com/MariaDB/server/commit/f6fcfc1a6a058fd7cac6bf53216ea73f3a04b22d
            sysprg Julius Goryavsky added a comment - Fixes have been backported to 10.5: https://github.com/MariaDB/server/commit/901c6c7ab63f9c9473b90d3f62be656321bcf871 + https://github.com/MariaDB/server/commit/d1f2ceee1bb1d33e181b5f35b12ed8536a8a0d24

            People

              sysprg Julius Goryavsky
              denis.protivensky Denis Protivensky
              Votes:
              0 Vote for this issue
              Watchers:
              4 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.