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

lock_release_on_prepare_try() does not release lock if supremum bit is set along with other bits set in lock's bitmap

    XMLWordPrintable

Details

    Description

      Seems related to MDEV-30941. While it is not caused by MDEV-31949, it causes interference with testing of MDEV-31949 and re-testing of MDEV-32257.

      --source include/have_innodb.inc
      CREATE TABLE t2 (t1_a INT,b INT) ENGINE=InnoDB;
      SET SESSION pseudo_slave_mode=1;
      CREATE TABLE t1 (a INT KEY,b LONG) ENGINE=InnoDB;
      XA START 'a';
      INSERT INTO t1 SELECT * FROM t1;
      INSERT INTO t2 VALUES (0,0);
      XA END 'a';
      XA PREPARE 'a';
      DROP TABLE t1,t2;
      

      The outcomes for the final query differs significantly from version to version:

      10.4.32 47f0135d7aba57d160d1d95ff7f1f6b7bb07c2fb (Optimized + Debug)

      10.4.32>DROP TABLE t1,t2;
      ERROR 1399 (XAE07): XAER_RMFAIL: The command cannot be executed when global transaction is in the  PREPARED state
      

      10.5.23 6b343de8ef51e4c92f0ea2bf62f27f0aab32204d (Optimized)

      10.5.23-opt>DROP TABLE t1,t2;
      Query OK, 0 rows affected (0.008 sec)
      

      10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Debug)

      10.6.16-dbg>DROP TABLE t1,t2;
      ERROR 2013 (HY000): Lost connection to server during query
      

      10.9.8 3e0009dc3a771e4dbf2fa4a4cf87e750453fb2eb (Debug)

      10.9.8-dbg>DROP TABLE t1,t2;
      ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
      

      10.10+ versions all show the ERROR 1205 Lock wait timeout.
      An example of the process list during before the timeout happens:

      10.9.8 3e0009dc3a771e4dbf2fa4a4cf87e750453fb2eb (Debug)

      10.9.8-dbg>SHOW PROCESSLIST;
      +----+------+-----------+------+---------+------+----------------+------------------+----------+
      | Id | User | Host      | db   | Command | Time | State          | Info             | Progress |
      +----+------+-----------+------+---------+------+----------------+------------------+----------+
      |  4 | root | localhost | test | Query   |   29 | closing tables | DROP TABLE t1,t2 |    0.000 |
      |  5 | root | localhost | test | Query   |    0 | starting       | SHOW PROCESSLIST |    0.000 |
      +----+------+-----------+------+---------+------+----------------+------------------+----------+
      2 rows in set (0.000 sec)
      

      MySQL 5.5 to 5.7 show the ERROR 1399:

      MySQL 5.7.40 c4f63caa8d9f30b2850672291e0ad0928dd89d0e (Debug) and MS 5.5, MS 5.6

      5.7.40-dbg>DROP TABLE t1,t2;
      ERROR 1399 (XAE07): XAER_RMFAIL: The command cannot be executed when global transaction is in the  PREPARED state
      

      MySQL 8 is different again, it waits much longer and the process list shows:

      MySQL 8.0.33 ea7087d885006918ad54458e7aad215b1650312c (Optimized)

      mysql> SHOW PROCESSLIST;
      +----+-----------------+-----------+------+---------+------+---------------------------------+------------------+
      | Id | User            | Host      | db   | Command | Time | State                           | Info             |
      +----+-----------------+-----------+------+---------+------+---------------------------------+------------------+
      |  5 | event_scheduler | localhost | NULL | Daemon  |  476 | Waiting on empty queue          | NULL             |
      |  9 | root            | localhost | test | Query   |  474 | Waiting for table metadata lock | DROP TABLE t1,t2 |
      | 10 | root            | localhost | test | Query   |    0 | init                            | SHOW PROCESSLIST |
      +----+-----------------+-----------+------+---------+------+---------------------------------+------------------+
      3 rows in set (0.00 sec)
      

      The stacks for the crash on 10.6 opt/dbg:

      10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Optimized)

      2023-09-28 09:49:54 0x149808da3640  InnoDB: Assertion failure in file /test/10.6_opt/storage/innobase/dict/dict0dict.cc line 1862
      InnoDB: Failing assertion: table->n_rec_locks == 0
      

      10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Optimized)

      Core was generated by `/test/MD270923-mariadb-10.6.16-linux-x86_64-opt/bin/mariadbd --no-defaults --co'.
      Program terminated with signal SIGABRT, Aborted.
      #0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=22643216102976)
          at ./nptl/pthread_kill.c:44
      [Current thread is 1 (Thread 0x149808da3640 (LWP 4001869))]
      (gdb) bt
      #0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=22643216102976) at ./nptl/pthread_kill.c:44
      #1  __pthread_kill_internal (signo=6, threadid=22643216102976) at ./nptl/pthread_kill.c:78
      #2  __GI___pthread_kill (threadid=22643216102976, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
      #3  0x0000149813642476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
      #4  0x00001498136287f3 in __GI_abort () at ./stdlib/abort.c:79
      #5  0x00005627b9753f5f in ut_dbg_assertion_failed (expr=expr@entry=0x5627ba412374 "table->n_rec_locks == 0", file=file@entry=0x5627ba412390 "/test/10.6_opt/storage/innobase/dict/dict0dict.cc", line=line@entry=1862) at /test/10.6_opt/storage/innobase/ut/ut0dbg.cc:60
      #6  0x00005627b9760a48 in dict_sys_t::remove (this=0x5627baa0a500 <dict_sys>, table=table@entry=0x1497a401f520, lru=lru@entry=false, keep=keep@entry=false) at /test/10.6_opt/storage/innobase/dict/dict0dict.cc:1862
      #7  0x00005627b9f9e214 in trx_t::commit (this=this@entry=0x14980a05d180, deleted=std::vector of length 0, capacity 0) at /test/10.6_opt/storage/innobase/dict/drop.cc:276
      #8  0x00005627b9e329d4 in ha_innobase::delete_table (this=<optimized out>, name=<optimized out>) at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:13782
      #9  0x00005627b9af2245 in hton_drop_table (hton=<optimized out>, path=<optimized out>) at /test/10.6_opt/sql/handler.cc:573
      #10 0x00005627b9af8bb9 in ha_delete_table (thd=thd@entry=0x1497a4000c68, hton=hton@entry=0x5627bbbbb658, path=path@entry=0x149808da1160 "./test/t1", db=db@entry=0x149808da0f50, alias=alias@entry=0x149808da0f60, generate_warning=generate_warning@entry=true) at /test/10.6_opt/sql/handler.cc:3163
      #11 0x00005627b9942cbe in mysql_rm_table_no_locks (thd=0x1497a4000c68, tables=<optimized out>, current_db=<optimized out>, ddl_log_state=<optimized out>, if_exists=<optimized out>, drop_temporary=<optimized out>, drop_view=<optimized out>, drop_sequence=<optimized out>, dont_log_query=<optimized out>, dont_free_locks=<optimized out>) at /test/10.6_opt/sql/sql_table.cc:1464
      #12 0x00005627b994425c in mysql_rm_table (thd=thd@entry=0x1497a4000c68, tables=tables@entry=0x1497a40109c8, if_exists=<optimized out>, drop_temporary=<optimized out>, drop_sequence=<optimized out>, dont_log_query=dont_log_query@entry=false) at /test/10.6_opt/sql/sql_table.cc:1041
      #13 0x00005627b98a719a in mysql_execute_command (thd=0x1497a4000c68, is_called_from_prepared_stmt=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:4978
      #14 0x00005627b98ab6e6 in mysql_parse (thd=0x1497a4000c68, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:8050
      #15 0x00005627b98ade85 in dispatch_command (command=COM_QUERY, thd=0x1497a4000c68, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:1995
      #16 0x00005627b98afbf0 in do_command (thd=0x1497a4000c68, blocking=blocking@entry=true) at /test/10.6_opt/sql/sql_parse.cc:1409
      #17 0x00005627b99c024f in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at /test/10.6_opt/sql/sql_connect.cc:1416
      #18 0x00005627b99c059d in handle_one_connection (arg=arg@entry=0x5627bc0317c8) at /test/10.6_opt/sql/sql_connect.cc:1318
      #19 0x00005627b9d724f1 in pfs_spawn_thread (arg=0x5627bbfc1e28) at /test/10.6_opt/storage/perfschema/pfs.cc:2201
      #20 0x0000149813694b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
      #21 0x0000149813726a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
      

      10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Debug)

      2023-09-28 10:04:17 0x152fa0953640  InnoDB: Assertion failure in file /test/10.6_dbg/storage/innobase/dict/dict0dict.cc line 1862
      InnoDB: Failing assertion: table->n_rec_locks == 0
      

      10.6.16 076df87b4c1dc5123d66600b82201050c45aa9d9 (Debug)

      Core was generated by `/test/MD270923-mariadb-10.6.16-linux-x86_64-dbg/bin/mariadbd --no-defaults --co'.
      Program terminated with signal SIGABRT, Aborted.
      #0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=23294301779520)
          at ./nptl/pthread_kill.c:44
      [Current thread is 1 (Thread 0x152fa0953640 (LWP 2586101))]
      (gdb) bt
      #0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=23294301779520) at ./nptl/pthread_kill.c:44
      #1  __pthread_kill_internal (signo=6, threadid=23294301779520) at ./nptl/pthread_kill.c:78
      #2  __GI___pthread_kill (threadid=23294301779520, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
      #3  0x0000152fb6c42476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
      #4  0x0000152fb6c287f3 in __GI_abort () at ./stdlib/abort.c:79
      #5  0x000055e0d4e591a4 in ut_dbg_assertion_failed (expr=expr@entry=0x55e0d54838a4 "table->n_rec_locks == 0", file=file@entry=0x55e0d5483988 "/test/10.6_dbg/storage/innobase/dict/dict0dict.cc", line=line@entry=1862) at /test/10.6_dbg/storage/innobase/ut/ut0dbg.cc:60
      #6  0x000055e0d4f0ba5b in dict_sys_t::remove (this=0x55e0d5a95a00 <dict_sys>, table=table@entry=0x152f6401d548, lru=lru@entry=false, keep=keep@entry=false) at /test/10.6_dbg/storage/innobase/dict/dict0dict.cc:1862
      #7  0x000055e0d4f3b9e9 in trx_t::commit (this=this@entry=0x152fa1956180, deleted=std::vector of length 0, capacity 0) at /test/10.6_dbg/storage/innobase/dict/drop.cc:276
      #8  0x000055e0d4c55c54 in ha_innobase::delete_table (this=<optimized out>, name=<optimized out>) at /test/10.6_dbg/storage/innobase/handler/ha_innodb.cc:13782
      #9  0x000055e0d48ba4e1 in hton_drop_table (hton=<optimized out>, path=<optimized out>) at /test/10.6_dbg/sql/handler.cc:573
      #10 0x000055e0d48c2f5f in ha_delete_table (thd=thd@entry=0x152f64000d58, hton=hton@entry=0x55e0d7edfb28, path=path@entry=0x152fa09517b0 "./test/t1", db=db@entry=0x152fa09515a0, alias=alias@entry=0x152fa09515b0, generate_warning=generate_warning@entry=true) at /test/10.6_dbg/sql/handler.cc:3163
      #11 0x000055e0d46b6d20 in mysql_rm_table_no_locks (thd=thd@entry=0x152f64000d58, tables=tables@entry=0x152f64013388, current_db=current_db@entry=0x152f64000df8, ddl_log_state=0x152fa09515d0, ddl_log_state@entry=0x0, if_exists=if_exists@entry=false, drop_temporary=drop_temporary@entry=false, drop_view=false, drop_sequence=false, dont_log_query=false, dont_free_locks=false) at /test/10.6_dbg/sql/sql_table.cc:1464
      #12 0x000055e0d46b8bb4 in mysql_rm_table (thd=thd@entry=0x152f64000d58, tables=tables@entry=0x152f64013388, if_exists=<optimized out>, drop_temporary=<optimized out>, drop_sequence=<optimized out>, dont_log_query=dont_log_query@entry=false) at /test/10.6_dbg/sql/sql_table.cc:1041
      #13 0x000055e0d460287d in mysql_execute_command (thd=thd@entry=0x152f64000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.6_dbg/sql/sql_parse.cc:4978
      #14 0x000055e0d4607164 in mysql_parse (thd=thd@entry=0x152f64000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x152fa09521f0) at /test/10.6_dbg/sql/sql_parse.cc:8050
      #15 0x000055e0d46094da in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x152f64000d58, packet=packet@entry=0x152f6400af29 "DROP TABLE t1,t2", packet_length=packet_length@entry=16, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:241
      #16 0x000055e0d460b5f7 in do_command (thd=0x152f64000d58, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1409
      #17 0x000055e0d474a1fd in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e0d83b4fa8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1416
      #18 0x000055e0d474a4f2 in handle_one_connection (arg=arg@entry=0x55e0d83b4fa8) at /test/10.6_dbg/sql/sql_connect.cc:1318
      #19 0x000055e0d4b9608c in pfs_spawn_thread (arg=0x55e0d8399708) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
      #20 0x0000152fb6c94b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
      #21 0x0000152fb6d26a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
      

      Attachments

        Issue Links

          Activity

            People

              vlad.lesin Vladislav Lesin
              Roel Roel Van de Paar
              Votes:
              0 Vote for this issue
              Watchers:
              5 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.