Bug #87393 xa rollback with wrong xid will be recorded into the binlog
Submitted: 11 Aug 2017 8:58 Modified: 29 Sep 2017 11:20
Reporter: HongXiang Jiang (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: XA transactions Severity:S2 (Serious)
Version:5.7.19 OS:Linux
Assigned to: CPU Architecture:Any
Tags: binlog, XA ROLLBACK

[11 Aug 2017 8:58] HongXiang Jiang
Description:
If we start a XA transaction and prepared it. then, if we do 'XA rollback' with the wrong xid, the "XA rollback" will execute failed. but the "XA rollback" has been recorded into the binlog with the right xid. If in the replication, the master do the 'xa rollback' with the wrong xid, rollback failed, but on slave, maybe rollback succeed. 

How to repeat:
create table t(id int primary key)engine=innodb;

start a session to do like below:

xa start '1';
insert into t values(1);
xa end '1';
xa prepare '1';
xa rollback '2';  //xa rollback with the wrong xid

after doing above, the "xa rollback '2'" execute failed, but this operation is recorded into the binlog with the xid '1', use another session to do: show binlog events, the result is:

+------------------+-----+----------------+-----------+-------------+---------------------------------------+
| Log_name         | Pos | Event_type     | Server_id | End_log_pos | Info                                  |
+------------------+-----+----------------+-----------+-------------+---------------------------------------+
| mysql-bin.000001 |   4 | Format_desc    |        11 |         123 | Server ver: 5.7.19-log, Binlog ver: 4 |
| mysql-bin.000001 | 123 | Previous_gtids |        11 |         150 |                                       |
| mysql-bin.000001 | 150 | Anonymous_Gtid |        11 |         211 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'  |
| mysql-bin.000001 | 211 | Query          |        11 |         294 | XA START X'31',X'',1                  |
| mysql-bin.000001 | 294 | Table_map      |        11 |         334 | table_id: 220 (mydb.t)                |
| mysql-bin.000001 | 334 | Write_rows     |        11 |         370 | table_id: 220 flags: STMT_END_F       |
| mysql-bin.000001 | 370 | Query          |        11 |         451 | XA END X'31',X'',1                    |
| mysql-bin.000001 | 451 | XA_prepare     |        11 |         484 | XA PREPARE X'31',X'',1                |
| mysql-bin.000001 | 484 | Anonymous_Gtid |        11 |         545 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'  |
| mysql-bin.000001 | 545 | Query          |        11 |         631 | XA ROLLBACK X'31',X'',1               |
+------------------+-----+----------------+-----------+-------------+---------------------------------------+

also you can use mysqlbinlog -v to check it in the binlog file:

XA START X'31',X'',1
/*!*/;
# at 294
#170811 16:21:02 server id 11  end_log_pos 334 	Table_map: `mydb`.`t` mapped to number 220
# at 334
#170811 16:21:02 server id 11  end_log_pos 370 	Write_rows: table id 220 flags: STMT_END_F

BINLOG '
7miNWRMLAAAAKAAAAE4BAAAAANwAAAAAAAEABG15ZGIAAXQAAQMAAA==
7miNWR4LAAAAJAAAAHIBAAAAANwAAAAAAAEAAgAB//4BAAAA
'/*!*/;
### INSERT INTO `mydb`.`t`
### SET
###   @1=1
# at 370
#170811 16:21:16 server id 11  end_log_pos 451 	Query	thread_id=3	exec_time=0	error_code=0
SET TIMESTAMP=1502439676/*!*/;
XA END X'31',X'',1
/*!*/;
# at 451
#170811 16:21:16 server id 11  end_log_pos 484 	XA PREPARE X'31',X'',1
XA PREPARE X'31',X'',1
/*!*/;
# at 484
#170811 16:21:27 server id 11  end_log_pos 545 	Anonymous_GTID	last_committed=1	sequence_number=2	rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 545
#170811 16:21:27 server id 11  end_log_pos 631 	Query	thread_id=3	exec_time=0	error_code=0
SET TIMESTAMP=1502439687/*!*/;
XA ROLLBACK X'31',X'',1
/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file

The last log event is: XA ROLLBACK X'31',X'',1, this log event maybe incorrect!!

Suggested fix:
if the xa rollback with wrong xid, it will not be recorded into binlog.

maybe modify the function binlog.cc:MYSQL_BIN_LOG::rollback, when do the SQLCOM_XA_ROLLBACK command, check the xid is the same or not, if not the same, do not write the binlog.
[11 Aug 2017 10:46] HongXiang Jiang
patched on mysql-5.7.19, please review it

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: xa_rollback_fix.patch (application/octet-stream, text), 1.07 KiB.

[11 Aug 2017 13:41] Sinisa Milivojevic
Hi!

I have run the same transaction and you and got the same result. I also think that your patch is correct.

Verified.
[29 Sep 2017 11:20] Margaret Fisher
Posted by developer:
 
Changelog entry added for MySQL 8.0.4 and 5.7.21:
XA ROLLBACK statements that failed because an incorrect transaction ID was given, could be recorded in the binary log with the correct transaction ID, and could therefore be actioned by replication slaves. A check is now made for the error situation before binary logging takes place, and failed XA ROLLBACK statements are not logged.
[7 Nov 2017 8:56] Venkatesh Duggirala
Post by Developer:
==================

Bug#88358 is marked as duplicate of this bug

Regards,
Venkatesh.
[18 May 7:36] Umesh Shastry
Bug #90928 marked as duplicate of this one