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

InnoDB fails to return error for XA COMMIT or XA ROLLBACK in read-only mode

Details

    Description

      --source include/have_innodb.inc
      --source include/have_binlog_format_mixed.inc
      CREATE TABLE t1 (i INT) ENGINE=InnoDB;
      INSERT IGNORE INTO t1 VALUES (1);
      --let $shutdown_timeout= 0
      --let $restart_parameters= --innodb-force-recovery=3
      --source include/restart_mysqld.inc
      --let $shutdown_timeout= 30
      --let $restart_parameters= --innodb-force-recovery=0 --innodb-read-only=1 --tc-heuristic-recover=ROLLBACK
      --source include/restart_mysqld.inc
      

      10.0 60c9485a8e5ebf410d9fa60caa7937f3fe3ca9b8

      170803 17:26:09 [Note] Heuristic crash recovery mode
      2017-08-03 17:26:09 7f3ac8727080  InnoDB: Starting recovery for XA transactions...
      2017-08-03 17:26:09 7f3ac8727080  InnoDB: Transaction 1283 in prepared state after recovery
      2017-08-03 17:26:09 7f3ac8727080  InnoDB: Transaction contains changes to 1 rows
      2017-08-03 17:26:09 7f3ac8727080  InnoDB: 1 transactions in prepared state after recovery
      170803 17:26:09 [Note] Found 1 prepared transaction(s) in InnoDB
      170803 17:26:09 [Note] rollback xid 'MySQLXid\1\0\0\0\0\0\0\0\26\0\0\0\0\0\0\0'
      2017-08-03 17:26:09 7f3ac8727080  InnoDB: Assertion failure in thread 139890447773824 in file mtr0mtr.cc line 322
      InnoDB: Failing assertion: !srv_read_only_mode
      

      #5  0x00007f3ac63a43fa in abort () from /lib/x86_64-linux-gnu/libc.so.6
      #6  0x00007f3abebbcf9f in mtr_commit (mtr=0x7ffd79958de0) at /data/src/10.0/storage/innobase/mtr/mtr0mtr.cc:322
      #7  0x00007f3abec67ec1 in btr_pcur_commit_specify_mtr (pcur=0x7f3ac587f6e8, mtr=0x7ffd79958de0) at /data/src/10.0/storage/innobase/include/btr0pcur.ic:386
      #8  0x00007f3abec68735 in row_undo_ins_remove_clust_rec (node=0x7f3ac587f678) at /data/src/10.0/storage/innobase/row/row0uins.cc:170
      #9  0x00007f3abec68f72 in row_undo_ins (node=0x7f3ac587f678) at /data/src/10.0/storage/innobase/row/row0uins.cc:461
      #10 0x00007f3abec70af3 in row_undo (node=0x7f3ac587f678, thr=0x7f3ac583cc40) at /data/src/10.0/storage/innobase/row/row0undo.cc:304
      #11 0x00007f3abec70c21 in row_undo_step (thr=0x7f3ac583cc40) at /data/src/10.0/storage/innobase/row/row0undo.cc:351
      #12 0x00007f3abebf861f in que_thr_step (thr=0x7f3ac583cc40) at /data/src/10.0/storage/innobase/que/que0que.cc:1077
      #13 0x00007f3abebf883f in que_run_threads_low (thr=0x7f3ac583cc40) at /data/src/10.0/storage/innobase/que/que0que.cc:1141
      #14 0x00007f3abebf89cb in que_run_threads (thr=0x7f3ac583cc40) at /data/src/10.0/storage/innobase/que/que0que.cc:1182
      #15 0x00007f3abecac7d0 in trx_rollback_to_savepoint_low (trx=0x7f3ac587cc78, savept=0x0) at /data/src/10.0/storage/innobase/trx/trx0roll.cc:113
      #16 0x00007f3abecacb34 in trx_rollback_for_mysql_low (trx=0x7f3ac587cc78) at /data/src/10.0/storage/innobase/trx/trx0roll.cc:176
      #17 0x00007f3abecaceac in trx_rollback_for_mysql (trx=0x7f3ac587cc78) at /data/src/10.0/storage/innobase/trx/trx0roll.cc:211
      #18 0x00007f3abeb4141f in innobase_rollback_trx (trx=0x7f3ac587cc78) at /data/src/10.0/storage/innobase/handler/ha_innodb.cc:4056
      #19 0x00007f3abeb54045 in innobase_rollback_by_xid (hton=0x7f3ac0d17270, xid=0x7f3abb000070) at /data/src/10.0/storage/innobase/handler/ha_innodb.cc:14479
      #20 0x000000000083b2b2 in xarecover_handlerton (unused=0x0, plugin=0x7ffd79959888, arg=0x7ffd799598f0) at /data/src/10.0/sql/handler.cc:1855
      #21 0x0000000000662379 in plugin_foreach_with_mask (thd=0x0, func=0x83afcf <xarecover_handlerton(THD*, plugin_ref, void*)>, type=1, state_mask=4294967287, arg=0x7ffd799598f0) at /data/src/10.0/sql/sql_plugin.cc:2336
      #22 0x000000000083b522 in ha_recover (commit_list=0x0) at /data/src/10.0/sql/handler.cc:1898
      #23 0x0000000000917fb1 in TC_LOG::using_heuristic_recover (this=0x17acd00 <mysql_bin_log>) at /data/src/10.0/sql/log.cc:8938
      #24 0x000000000091808d in MYSQL_BIN_LOG::open (this=0x17acd00 <mysql_bin_log>, opt_name=0x7f3ac1bbf838 "master-bin") at /data/src/10.0/sql/log.cc:8961
      #25 0x00000000005925e9 in init_server_components () at /data/src/10.0/sql/mysqld.cc:4905
      #26 0x0000000000593167 in mysqld_main (argc=138, argv=0x7f3ac5878ac0) at /data/src/10.0/sql/mysqld.cc:5371
      #27 0x0000000000589c76 in main (argc=23, argv=0x7ffd79959d78) at /data/src/10.0/sql/main.cc:25
      

      Attachments

        Issue Links

          Activity

            Andrei, can you debug this further? I tried with the following patch to both storage/innobase and storage/xtradb, and it will fail in binlog:

            diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc
            index 526836646d2..031ab54d4c5 100644
            --- a/storage/innobase/handler/ha_innodb.cc
            +++ b/storage/innobase/handler/ha_innodb.cc
            @@ -14446,6 +14446,10 @@ innobase_commit_by_xid(
             
             	DBUG_ASSERT(hton == innodb_hton_ptr);
             
            +	if (high_level_read_only) {
            +		return(XAER_RMFAIL);
            +	}
            +
             	trx = trx_get_trx_by_xid(xid);
             
             	if (trx) {
            @@ -14473,6 +14477,10 @@ innobase_rollback_by_xid(
             
             	DBUG_ASSERT(hton == innodb_hton_ptr);
             
            +	if (high_level_read_only) {
            +		return(XAER_RMFAIL);
            +	}
            +
             	trx = trx_get_trx_by_xid(xid);
             
             	if (trx) {
            

            The failure was like this:

            170807 14:19:29 [Note] Heuristic crash recovery mode
            2017-08-07 14:19:29 7fc95dcc0540  InnoDB: Starting recovery for XA transactions...
            2017-08-07 14:19:29 7fc95dcc0540  InnoDB: Transaction 1283 in prepared state after recovery
            2017-08-07 14:19:29 7fc95dcc0540  InnoDB: Transaction contains changes to 1 rows
            2017-08-07 14:19:29 7fc95dcc0540  InnoDB: 1 transactions in prepared state after recovery
            170807 14:19:29 [Note] Found 1 prepared transaction(s) in InnoDB
            170807 14:19:29 [Note] rollback xid 'MySQLXid\1\0\0\0\0\0\0\0\26\0\0\0\0\0\0\0'
            170807 14:19:29 [Note] Please restart mysqld without --tc-heuristic-recover
            mysqld: /mariadb/10.0/sql/log.cc:3258: bool MYSQL_BIN_LOG::open(const char *, enum_log_type, const char *, enum cache_type, ulong, bool, bool): Assertion `(&(&LOCK_log)->m_mutex)->count > 0 && pthread_equal(pthread_self(), (&(&LOCK_log)->m_mutex)->thread)' failed.
            170807 14:19:29 [ERROR] mysqld got signal 6 ;
            

            Stack trace:

            #7  0x00007fc95c446f12 in __GI___assert_fail (assertion=0x10c994a "(&(&LOCK_log)->m_mutex)->count > 0 && pthread_equal(pthread_self(), (&(&LOCK_log)->m_mutex)->thread)", file=0x10c8c0e "/mariadb/10.0/sql/log.cc", line=3258, function=0x10c99af "bool MYSQL_BIN_LOG::open(const char *, enum_log_type, const char *, enum cache_type, ulong, bool, bool)") at assert.c:101
            #8  0x0000000000934a7c in MYSQL_BIN_LOG::open (this=0x18b7820 <mysql_bin_log>, log_name=0x3c13d98 "master-bin", log_type_arg=LOG_BIN, new_name=0x0, io_cache_type_arg=WRITE_CACHE, max_size_arg=1073741824, null_created_arg=false, need_mutex=true) at /mariadb/10.0/sql/log.cc:3258
            #9  0x0000000000943bde in MYSQL_BIN_LOG::open (this=0x18b7820 <mysql_bin_log>, opt_name=0x3c13d98 "master-bin") at /mariadb/10.0/sql/log.cc:8964
            #10 0x000000000057e8f2 in init_server_components () at /mariadb/10.0/sql/mysqld.cc:4905
            #11 0x000000000057b5c4 in mysqld_main (argc=137, argv=0x3af0388) at /mariadb/10.0/sql/mysqld.cc:5371
            #12 0x00000000005782c2 in main (argc=22, argv=0x7ffc17d97628) at /mariadb/10.0/sql/main.cc:25
            

            It appears that a mutex is not being released in an error handling code path.

            marko Marko Mäkelä added a comment - Andrei, can you debug this further? I tried with the following patch to both storage/innobase and storage/xtradb, and it will fail in binlog: diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index 526836646d2..031ab54d4c5 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -14446,6 +14446,10 @@ innobase_commit_by_xid( DBUG_ASSERT(hton == innodb_hton_ptr); + if (high_level_read_only) { + return(XAER_RMFAIL); + } + trx = trx_get_trx_by_xid(xid); if (trx) { @@ -14473,6 +14477,10 @@ innobase_rollback_by_xid( DBUG_ASSERT(hton == innodb_hton_ptr); + if (high_level_read_only) { + return(XAER_RMFAIL); + } + trx = trx_get_trx_by_xid(xid); if (trx) { The failure was like this: 170807 14:19:29 [Note] Heuristic crash recovery mode 2017-08-07 14:19:29 7fc95dcc0540 InnoDB: Starting recovery for XA transactions... 2017-08-07 14:19:29 7fc95dcc0540 InnoDB: Transaction 1283 in prepared state after recovery 2017-08-07 14:19:29 7fc95dcc0540 InnoDB: Transaction contains changes to 1 rows 2017-08-07 14:19:29 7fc95dcc0540 InnoDB: 1 transactions in prepared state after recovery 170807 14:19:29 [Note] Found 1 prepared transaction(s) in InnoDB 170807 14:19:29 [Note] rollback xid 'MySQLXid\1\0\0\0\0\0\0\0\26\0\0\0\0\0\0\0' 170807 14:19:29 [Note] Please restart mysqld without --tc-heuristic-recover mysqld: /mariadb/10.0/sql/log.cc:3258: bool MYSQL_BIN_LOG::open(const char *, enum_log_type, const char *, enum cache_type, ulong, bool, bool): Assertion `(&(&LOCK_log)->m_mutex)->count > 0 && pthread_equal(pthread_self(), (&(&LOCK_log)->m_mutex)->thread)' failed. 170807 14:19:29 [ERROR] mysqld got signal 6 ; Stack trace: #7 0x00007fc95c446f12 in __GI___assert_fail (assertion=0x10c994a "(&(&LOCK_log)->m_mutex)->count > 0 && pthread_equal(pthread_self(), (&(&LOCK_log)->m_mutex)->thread)", file=0x10c8c0e "/mariadb/10.0/sql/log.cc", line=3258, function=0x10c99af "bool MYSQL_BIN_LOG::open(const char *, enum_log_type, const char *, enum cache_type, ulong, bool, bool)") at assert.c:101 #8 0x0000000000934a7c in MYSQL_BIN_LOG::open (this=0x18b7820 <mysql_bin_log>, log_name=0x3c13d98 "master-bin", log_type_arg=LOG_BIN, new_name=0x0, io_cache_type_arg=WRITE_CACHE, max_size_arg=1073741824, null_created_arg=false, need_mutex=true) at /mariadb/10.0/sql/log.cc:3258 #9 0x0000000000943bde in MYSQL_BIN_LOG::open (this=0x18b7820 <mysql_bin_log>, opt_name=0x3c13d98 "master-bin") at /mariadb/10.0/sql/log.cc:8964 #10 0x000000000057e8f2 in init_server_components () at /mariadb/10.0/sql/mysqld.cc:4905 #11 0x000000000057b5c4 in mysqld_main (argc=137, argv=0x3af0388) at /mariadb/10.0/sql/mysqld.cc:5371 #12 0x00000000005782c2 in main (argc=22, argv=0x7ffc17d97628) at /mariadb/10.0/sql/main.cc:25 It appears that a mutex is not being released in an error handling code path.

            Also, it looks like we should revert part of this InnoDB change in MySQL 5.0.3 (making innodb_force_recovery=1 and innodb_force_recovery=2 initiate rollback of a transaction that reached the XA PREPARE state before previous crash or shutdown).
            It seems that the option tc_heuristic_recover=ROLLBACK was introduced for exactly this purpose; there is no need to convolute the logic of an InnoDB parameter.

            marko Marko Mäkelä added a comment - Also, it looks like we should revert part of this InnoDB change in MySQL 5.0.3 (making innodb_force_recovery=1 and innodb_force_recovery=2 initiate rollback of a transaction that reached the XA PREPARE state before previous crash or shutdown). It seems that the option tc_heuristic_recover=ROLLBACK was introduced for exactly this purpose; there is no need to convolute the logic of an InnoDB parameter.
            Elkin Andrei Elkin added a comment -

            Elena, hello.

            There are small changes to mtr that's why you.

            I am asking Marko to review the rest of this work.
            The latest patch is pushed to bb-10.0-mdev_13437-andrei.

            Thanks!

            Andrei

            Elkin Andrei Elkin added a comment - Elena, hello. There are small changes to mtr that's why you. I am asking Marko to review the rest of this work. The latest patch is pushed to bb-10.0-mdev_13437-andrei. Thanks! Andrei

            The only change I see in MTR is exporting of an extra variable. It's not dangerous, so if it works for you, I have no objections. In general, we should invent a better way to fail-start the server, but it doesn't have to be done now.

            Re-assigning to Marko for real review.

            elenst Elena Stepanova added a comment - The only change I see in MTR is exporting of an extra variable. It's not dangerous, so if it works for you, I have no objections. In general, we should invent a better way to fail-start the server, but it doesn't have to be done now. Re-assigning to Marko for real review.

            Elkin, the new logic looks OK to me.
            I only requested some minor clean-up to both the code and the test case.

            marko Marko Mäkelä added a comment - Elkin , the new logic looks OK to me. I only requested some minor clean-up to both the code and the test case.

            Looks OK now; the newest revision to the test even works with Valgrind:

            main.tc_heuristic_recover 'innodb_plugin' [ pass ]  54201
            main.tc_heuristic_recover 'xtradb'       [ pass ]  73606
            valgrind_report                          [ pass ]
            

            marko Marko Mäkelä added a comment - Looks OK now; the newest revision to the test even works with Valgrind: main.tc_heuristic_recover 'innodb_plugin' [ pass ] 54201 main.tc_heuristic_recover 'xtradb' [ pass ] 73606 valgrind_report [ pass ]

            People

              Elkin Andrei Elkin
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

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