MySQL Bugs: #88733: XA trx with binlog_format=MIXED writes binlogs in SBR

Bug #88733	XA trx with binlog_format=MIXED writes binlogs in SBR
Submitted:	1 Dec 2017 18:08	Modified:	3 Dec 2017 15:49
Reporter:	Kenny Gryp	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: XA transactions	Severity:	S3 (Non-critical)
Version:	5.7.19	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
As documented on https://dev.mysql.com/doc/refman/5.7/en/xa-restrictions.html

```
When binlog_format=MIXED or binlog_format=ROW is set, DML statements inside XA transactions are logged using row-based replication, and the potential issue is not present.
```

This is not true, events still get written as SBR

How to repeat:

mysql> set transaction isolation level repeatable read;
Query OK, 0 rows affected (0.00 sec)

mysql> set binlog_format='mixed';
Query OK, 0 rows affected (0.00 sec)

mysql> show master status;
+--------------------------+-----------+--------------+------------------+-------------------+
| File                     | Position  | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+--------------------------+-----------+--------------+------------------+-------------------+
| perconaserver-bin.000037 | 470238931 |              |                  |                   |
+--------------------------+-----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

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

mysql> insert into t1 values (1512515, null);
Query OK, 1 row affected (0.00 sec)

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

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

mysql> show binlog events in 'perconaserver-bin.000037' from 470238931;
+--------------------------+-----------+----------------+-----------+-------------+-------------------------------------------------------+
| Log_name                 | Pos       | Event_type     | Server_id | End_log_pos | Info                                                  |
+--------------------------+-----------+----------------+-----------+-------------+-------------------------------------------------------+
| perconaserver-bin.000037 | 470238931 | Anonymous_Gtid |         1 |   470238996 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                  |
| perconaserver-bin.000037 | 470238996 | Query          |         1 |   470239089 | XA START X'31',X'',1                                  |
| perconaserver-bin.000037 | 470239089 | Query          |         1 |   470239199 | use `xareprod`; insert into t1 values (1512515, null) |
| perconaserver-bin.000037 | 470239199 | Query          |         1 |   470239288 | XA END X'31',X'',1                                    |
| perconaserver-bin.000037 | 470239288 | XA_prepare     |         1 |   470239325 | XA PREPARE X'31',X'',1                                |
+--------------------------+-----------+----------------+-----------+-------------+-------------------------------------------------------+
5 rows in set (0.00 sec)

Suggested fix:

The event does not get logged RBR, but in SBR, even though the documentation says otherwise.

As it's unsafe to use SBR with XA, MIXED mode should always use RBR for XA. (Hence, this is not a documentation bug)

Hello Kenny Gryp,

Thank you for the report and test case.
This issue is not seen on 5.7.20, could you please confirm with latest
5.7.20 build?

rm -rf 88733
bin/mysqld --initialize-insecure --basedir=$PWD --datadir=$PWD/88733 
bin/mysqld --no-defaults --basedir=$PWD --datadir=$PWD/88733 --core-file
--socket=/tmp/mysql_ushastry.sock --port=33061 --log_bin --server_id=1
--log-error=$PWD/88733/log.err 2>&1 &

-- 5.6.19

[umshastr@hod03]/export/umesh/server/binaries/GABuilds/mysql-5.7.19: bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.7.19-log MySQL Community Server (GPL)

Copyright (c) 2000, 2017, 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> create database test;
Query OK, 1 row affected (0.00 sec)

mysql> use test
Database changed
mysql> create table t1(id int not null primary key, name varchar(100));                                                                                                     
Query OK, 0 rows affected (0.01 sec)

mysql> set transaction isolation level repeatable read;
Query OK, 0 rows affected (0.00 sec)

mysql> set binlog_format='mixed';
Query OK, 0 rows affected (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| hod03-bin.000001 |      515 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

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

mysql> insert into t1 values (1512515, null);
Query OK, 1 row affected (0.01 sec)

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

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

mysql> show binlog events in 'hod03-bin.000001' from 515;
+------------------+-----+----------------+-----------+-------------+---------------------------------------------------+
| Log_name         | Pos | Event_type     | Server_id | End_log_pos | Info                                              |
+------------------+-----+----------------+-----------+-------------+---------------------------------------------------+
| hod03-bin.000001 | 515 | Anonymous_Gtid |         1 |         580 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'              |
| hod03-bin.000001 | 580 | Query          |         1 |         674 | XA START X'31',X'',1                              |
| hod03-bin.000001 | 674 | Query          |         1 |         785 | use `test`; insert into t1 values (1512515, null) |
| hod03-bin.000001 | 785 | Query          |         1 |         870 | XA END X'31',X'',1                                |
| hod03-bin.000001 | 870 | XA_prepare     |         1 |         907 | XA PREPARE X'31',X'',1                            |
+------------------+-----+----------------+-----------+-------------+---------------------------------------------------+
5 rows in set (0.00 sec)

-- 5.7.20

[umshastr@hod03]/export/umesh/server/binaries/GABuilds/mysql-5.7.20: bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.7.20-log MySQL Community Server (GPL)

Copyright (c) 2000, 2017, 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>  create database test;
Query OK, 1 row affected (0.01 sec)

mysql> use test
Database changed
mysql> create table t1(id int not null primary key, name varchar(100));
Query OK, 0 rows affected (0.00 sec)

mysql> set transaction isolation level repeatable read;
Query OK, 0 rows affected (0.00 sec)

mysql> set binlog_format='mixed';
Query OK, 0 rows affected (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| hod03-bin.000001 |      515 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

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

mysql> insert into t1 values (1512515, null);
Query OK, 1 row affected (0.01 sec)

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

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

mysql> show binlog events in 'hod03-bin.000001' from 515;
+------------------+-----+----------------+-----------+-------------+--------------------------------------+
| Log_name         | Pos | Event_type     | Server_id | End_log_pos | Info                                 |
+------------------+-----+----------------+-----------+-------------+--------------------------------------+
| hod03-bin.000001 | 515 | Anonymous_Gtid |         1 |         580 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| hod03-bin.000001 | 580 | Query          |         1 |         667 | XA START X'31',X'',1                 |
| hod03-bin.000001 | 667 | Table_map      |         1 |         715 | table_id: 219 (test.t1)              |
| hod03-bin.000001 | 715 | Write_rows     |         1 |         755 | table_id: 219 flags: STMT_END_F      |
| hod03-bin.000001 | 755 | Query          |         1 |         840 | XA END X'31',X'',1                   |
| hod03-bin.000001 | 840 | XA_prepare     |         1 |         877 | XA PREPARE X'31',X'',1               |
+------------------+-----+----------------+-----------+-------------+--------------------------------------+
6 rows in set (0.00 sec)

Thanks,
Umesh

Yes it was something new in 5.7.20. Apologies, should have tested with latest first.
Duplicate of #85639

No problems, thank you for confirming.

Regards,
Umesh