Uploaded image for project: 'Percona Server for MySQL'
  1. Percona Server for MySQL
  2. PS-1401

LP #1204353: XA_PREPARED transaction rollbacked when client disconnect

Details

    Description

      **Reported in Launchpad by fengyi last update 30-03-2016 12:06:56

      This is a konwn issue, see http://bugs.mysql.com/bug.php?id=12161

      MySQL xa transaction has the following limitaitons:
      1. when client disconnects, XA_PREPARED transaction will be rollbacked.
      2. when server crashes, XA_PREPARED transactions can be found by 'XA RECOVER' and commit/rollback, but binlog are lost, which breaks the replication.

      2. is caused by the the optimization of binlog(no prepared log) , so that is not easy to fix.

      but 1. can be solved and there is no need to change any logic of binlog when fixing it, in http://bugs.mysql.com/bug.php?id=12161, feng shao proposed a solution as ha_semi_rollback_trans, which suspends the INNODB transaction for later commit/rollback, but it lost the binlog as 2.

      I have an idea to solve 1. while keep the binlog: suspend the disconnecting thd for later commit/rollback. The following is effect of the patch:

      ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

      mysql> reset master;
      Query OK, 0 rows affected (0.34 sec)

      mysql> show master logs;
      ---------------------------+

      Log_name File_size

      ---------------------------+

      mysql-bin.000001 107

      ---------------------------+
      1 row in set (0.00 sec)

      mysql> show create table test.t\G

                                                          • 1. row ***************************
                                                            Table: t
                                                            Create Table: CREATE TABLE `t` (
                                                            `id` int(11) NOT NULL AUTO_INCREMENT,
                                                            `num` int(11) DEFAULT NULL,
                                                            PRIMARY KEY (`id`)
                                                            ) ENGINE=InnoDB DEFAULT CHARSET=gbk
                                                            1 row in set (0.00 sec)

      mysql> select * from test.t;
      --------+

      id num

      --------+

      1 1

      --------+
      1 row in set (0.00 sec)

      mysql> xa start 'xa_2';
      Query OK, 0 rows affected (0.00 sec)

      mysql> insert into test.t(num) values(2);
      Query OK, 1 row affected (0.00 sec)

      mysql> xa end 'xa_2';
      Query OK, 0 rows affected (0.00 sec)

      mysql> xa prepare 'xa_2';
      Query OK, 0 rows affected (0.00 sec)

      mysql> quit
      Bye

                                                  • another session *********************

      $bin/mysql -uroot -S run/mysql.sock
      Welcome to the MySQL monitor. Commands end with ; or \g.
      Your MySQL connection id is 4096
      Server version: 5.5.18-tb3633-log Source distribution

      Copyright (c) 2000, 2011, Oracle and/or its affiliates. All rights reserved.

      Oracle is a registered trademark of Oracle Corporation and/or its
      affiliates. Other names may be trademarks of their respective
      owners.

      Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

      mysql> show processlist\G

                                                          • 1. row ***************************
                                                            Id: 4095
                                                            User: root
                                                            Host: localhost
                                                            db: NULL
                                                            Command: Killed
                                                            Time: 17
                                                            State: Waiting for xa commit/rollback
                                                            Info: NULL
                                                            Rows_sent: 0
                                                            Rows_examined: 0
                                                            Rows_read: 2
                                                          • 2. row ***************************
                                                            Id: 4096
                                                            User: root
                                                            Host: localhost
                                                            db: NULL
                                                            Command: Query
                                                            Time: 0
                                                            State: NULL
                                                            Info: show processlist
                                                            Rows_sent: 0
                                                            Rows_examined: 0
                                                            Rows_read: 1
                                                            2 rows in set (0.00 sec)

      mysql> xa recover;
      --------------------------------------+

      formatID gtrid_length bqual_length data

      --------------------------------------+

      1 4 0 xa_2

      --------------------------------------+
      1 row in set (0.00 sec)

      mysql> xa commit 'xa_2';
      Query OK, 0 rows affected (0.00 sec)

      mysql> select * from test.t;
      --------+

      id num

      --------+

      1 1
      2 2

      --------+
      2 rows in set (0.00 sec)

      mysql> xa recover;
      Empty set (0.00 sec)

      mysql> show processlist\G

                                                          • 1. row ***************************
                                                            Id: 4096
                                                            User: root
                                                            Host: localhost
                                                            db: NULL
                                                            Command: Query
                                                            Time: 0
                                                            State: NULL
                                                            Info: show processlist
                                                            Rows_sent: 0
                                                            Rows_examined: 0
                                                            Rows_read: 3
                                                            1 row in set (0.00 sec)

      mysql> show binlog events in 'mysql-bin.000001';
      ------------------------------------------------------------------------------------------------+

      Log_name Pos Event_type Server_id End_log_pos Info

      ------------------------------------------------------------------------------------------------+

      mysql-bin.000001 4 Format_desc 1 107 Server ver: 5.5.18-tb3633-log, Binlog ver: 4
      mysql-bin.000001 107 Query 1 171 BEGIN
      mysql-bin.000001 171 Table_map 1 212 table_id: 186 (test.t)
      mysql-bin.000001 212 Write_rows 1 250 table_id: 186 flags: STMT_END_F
      mysql-bin.000001 250 Query 1 315 COMMIT

      ------------------------------------------------------------------------------------------------+
      5 rows in set (0.00 sec)

      bin/mysqlbinlog -vvv log/mysql-bin.000001
      /!40019 SET @@session.max_insert_delayed_threads=0/;
      /!50003 SET @[email protected]@COMPLETION_TYPE,COMPLETION_TYPE=0/;
      DELIMITER /!/;

      1. at 4
        #130723 19:31:56 server id 1 end_log_pos 107 Start: binlog v 4, server v 5.5.18-tb3633-log created 130723 19:31:56 at startup
      2. Warning: this binlog is either in use or was not closed properly.
        ROLLBACK/!/;
        BINLOG '
        rGnuUQ8BAAAAZwAAAGsAAAABAAQANS41LjE4LXRiMzYzMy1sb2cAAAAAAAAAAAAAAAAAAAAAAAAA
        AAAAAAAAAAAAAAAAAACsae5REzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
        '/!/;
      3. at 107
        #130723 19:33:39 server id 1 end_log_pos 171 Query thread_id=4095 exec_time=48 error_code=0
        SET TIMESTAMP=1374579219/!/;
        SET @@session.pseudo_thread_id=4095/!/;
        SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/!/;
        SET @@session.sql_mode=0/!/;
        SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/!/;
        /Unable to render embedded object: File (\C utf8 *//*) not found./;
        SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=28/!/;
        SET @@session.lc_time_names=0/!/;
        SET @@session.collation_database=DEFAULT/!/;
        BEGIN
        /!/;
      4. at 171
      5. at 212
        #130723 19:33:00 server id 1 end_log_pos 212 Table_map: `test`.`t` mapped to number 186
        #130723 19:33:00 server id 1 end_log_pos 250 Write_rows: table id 186 flags: STMT_END_F

      BINLOG '
      7GnuURMBAAAAKQAAANQAAAAAALoAAAAAAAEABHRlc3QAAXQAAgMDAAI=
      7GnuURcBAAAAJgAAAPoAAAAAALoAAAAAAAEAAv/8AgAAAAIAAAA=
      '/!/;

          1. INSERT INTO test.t
          2. SET
          3. @1=2 /* INT meta=0 nullable=0 is_null=0 */
          4. @2=2 /* INT meta=0 nullable=1 is_null=0 */
      1. at 250
        #130723 19:33:39 server id 1 end_log_pos 315 Query thread_id=4095 exec_time=48 error_code=0
        SET TIMESTAMP=1374579219/!/;
        COMMIT
        /!/;
        DELIMITER ;
      2. End of log file
        ROLLBACK /* added by mysqlbinlog */;
        /!50003 SET [email protected]_COMPLETION_TYPE/;

      ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

      Hope someone can review the patch for me .

      Thanks.

      Attachments

        Activity

          People

            Unassigned Unassigned
            lpjirasync lpjirasync (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Smart Checklist