DDL is replicated even when sql_log_bin=0, and GTID is incremented in remote node

[markus_albe]

On PXC 5.7.18, CREATE TABLE is replicated even when sql_log_bin=0; And on top of that, GTID is incremented in remote node but not where the CREATE has run:

On node1:
PXC: root@localhost (sbtest) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1065
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-2
1 row in set (0.00 sec)

PXC: root@localhost (sbtest) > set sql_log_bin=0;
Query OK, 0 rows affected (0.00 sec)

PXC: root@localhost (sbtest) > create table nobinlog (i int not null auto_increment primary key) engine innodb;
Query OK, 0 rows affected (0.00 sec)

-- after the CREATE the local GTID was NOT incremented
PXC: root@localhost (sbtest) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1065
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-2
1 row in set (0.00 sec)

On node2:
-- before the CREATE
PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc2-bin.000002
         Position: 641
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-2
1 row in set (0.00 sec)

-- after the CREATE GTID was in fact incremented
PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc2-bin.000002
         Position: 863
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec)

PXC: root@localhost ((none)) > use sbtest;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

-- and the table was replicated!
Database changed
PXC: root@localhost (sbtest) > show tables;
+------------------+
| Tables_in_sbtest |
+------------------+
| nobinlog |
| sbtest1 |
+------------------+
2 rows in set (0.00 sec)

Not sure whether to file separate bug; Critical part seems to be the GTID bit since it makes the sequence inconsistent. But replicating tables when it's not desired seems a bug as well. If a separate bug is necessary, keep this for GTID part please and Support will file separate one.

Sample cnf:

[root@pxc2 /]# cat /etc/my.cnf
[mysql]
port = 3306
socket = /var/lib/mysql/mysql.sock
prompt='PXC: \u@\h (\d) > '

[client]
port = 3306
socket = /var/lib/mysql/mysql.sock

[mysqld]
socket = /var/lib/mysql/mysql.sock
datadir=/var/lib/mysql
user=mysql

wsrep_cluster_name=pxc_test

wsrep_provider=/usr/lib64/libgalera_smm.so
wsrep_provider_options = "gcs.fc_limit=500; gcs.fc_master_slave=YES; gcs.fc_factor=1.0; gcache.size=512M;"
wsrep_slave_threads = 2
wsrep_auto_increment_control = ON

wsrep_sst_method=xtrabackup-v2
wsrep_sst_auth=root:

wsrep_cluster_address=gcomm://10.0.3.21,10.0.3.227,10.0.3.35
wsrep_node_address=10.0.3.227
wsrep_node_name=percona2

innodb_locks_unsafe_for_binlog=1
innodb_autoinc_lock_mode=2
innodb_file_per_table=1
innodb-log-file-size = 256M
innodb-flush-log-at-trx-commit = 2
innodb-buffer-pool-size = 512M
innodb_use_native_aio = 0

log_bin
server_id=1
log_slave_updates
binlog_format=ROW
enforce_gtid_consistency=1
gtid_mode=on

[sst]
streamfmt=xbstream

[Jericho Rivera (jericho-rivera)]

Confirming bug on 5.6 as well but slightly different outcome:

On node1:
mysql> show master status;
+------------------+----------+--------------+------------------+------------------------------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+------------------------------------------+
| mysql-bin.000003 | 191 | | | 34408038-5c99-11e7-b402-00163e4de30b:1-4 |
+------------------+----------+--------------+------------------+------------------------------------------+
1 row in set (0.00 sec)

mysql> select @@sql_log_bin;
+---------------+
| @@sql_log_bin |
+---------------+
| 1 |
+---------------+
1 row in set (0.00 sec)

mysql> select @@global.sql_log_bin;
+----------------------+
| @@global.sql_log_bin |
+----------------------+
| 1 |
+----------------------+
1 row in set (0.00 sec)

mysql> set sql_log_bin=0;
Query OK, 0 rows affected (0.01 sec)

mysql> use test;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> create table nobinlog (id int primary key auto_increment not null, s varchar(10)) engine=innodb;
Query OK, 0 rows affected (0.03 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+------------------------------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+------------------------------------------+
| mysql-bin.000003 | 191 | | | 34408038-5c99-11e7-b402-00163e4de30b:1-4 |
+------------------+----------+--------------+------------------+------------------------------------------+
1 row in set (0.00 sec)

One node2:
before create table:
mysql> show master status;
+------------------+----------+--------------+------------------+------------------------------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+------------------------------------------+
| mysql-bin.000004 | 191 | | | 34408038-5c99-11e7-b402-00163e4de30b:1-4 |
+------------------+----------+--------------+------------------+------------------------------------------+
1 row in set (0.00 sec)

after create table:
mysql> show master status;
+------------------+----------+--------------+------------------+----------------------------------------------------------------------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+----------------------------------------------------------------------------------+
| mysql-bin.000004 | 408 | | | 34408038-5c99-11e7-b402-00163e4de30b:1-4,
4...

[Jericho Rivera (jericho-rivera)]

When wsrep_on is used to prevent replicating the CREATE:

On node1:
mysql> show master status;
+------------------+----------+--------------+------------------+----------------------------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+----------------------------------------+
| mysql-bin.000001 | 320 | | | 4dd1edef-ba4b-ee18-54a6-350f9802ffe9:1 |
+------------------+----------+--------------+------------------+----------------------------------------+
1 row in set (0.01 sec)

mysql> set wsrep_on=OFF;
Query OK, 0 rows affected (0.00 sec)

mysql> select @@wsrep_on;
+------------+
| @@wsrep_on |
+------------+
| 0 |
+------------+
1 row in set (0.00 sec)

mysql> create table nobinlog2 (id int primary key auto_increment, s varchar(10)) engine=innodb;
Query OK, 0 rows affected (0.03 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+--------------------------------------------------------------------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+--------------------------------------------------------------------------------+
| mysql-bin.000001 | 534 | | | 4dd1edef-ba4b-ee18-54a6-350f9802ffe9:1,
5eab47c5-404d-11e7-9b6a-00163ed78c40:1 |
+------------------+----------+--------------+------------------+--------------------------------------------------------------------------------+
1 row in set (0.00 sec)

On node2 before and after CREATE GTID did not increment:

mysql> show master status;
+------------------+----------+--------------+------------------+----------------------------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+----------------------------------------+
| mysql-bin.000001 | 320 | | | 4dd1edef-ba4b-ee18-54a6-350f9802ffe9:1 |
+------------------+----------+--------------+------------------+----------------------------------------+
1 row in set (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+----------------------------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+----------------------------------------+
| mysql-bin.000001 | 320 | | | 4dd1edef-ba4b-ee18-54a6-350f9802ffe9:1 |
+------------------+----------+--------------+------------------+----------------------------------------+
1 row in set (0.00 sec)

[Jericho Rivera (jericho-rivera)]

Comment #2 though is just to illustrate that with wsrep_on=OFF the CREATE TABLE is not replicated to the other node.

[markus_albe (markus-albe)]

The same happens with user management statements; On the same setup I did my initial testing:

node1, with sql_log_bin=1:

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1065
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-2
1 row in set (0.00 sec)

PXC: root@localhost ((none)) > CREATE USER 'demo'@'localhost' IDENTIFIED BY 's3kr3t';
Query OK, 0 rows affected (0.01 sec)

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1318
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec)

PXC: root@localhost ((none)) > SET sql_log_bin=0;
Query OK, 0 rows affected (0.00 sec)

PXC: root@localhost ((none)) > CREATE USER 'demo2'@'localhost' IDENTIFIED BY 's3kr3t';
Query OK, 0 rows affected (0.00 sec)

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1318
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec)

PXC: root@localhost ((none)) > DROP USER 'demo2'@'localhost' ;
Query OK, 0 rows affected (0.00 sec)

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1318
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec)

PXC: root@localhost ((none)) > GRANT ALL PRIVILEGES ON *.* TO 'demo'@'localhost';
Query OK, 0 rows affected (0.01 sec)

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1318
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec)

On node2 I ran SHOW MASTER STATUS after each command on node1:

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc2-bin.000002
         Position: 863
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec) ...

[Krunal Bauskar (krunal-bauskar)]

Let me re-define the problem.

* CREATE TABLE (or any DDL) is replicated using TOI and TOI doesn't need binlog write-set as it is statement level replication.

* DML needs binlog for write-set creation and so if DML is executed under sql_log_bin=0 then DML is not replicated.

Check the following test-case:

-------
create database test;
use test;
select @@global.gtid_executed;
create table nobinlog (i int not null auto_increment primary key) engine innodb;
insert into nobinlog values (1);
select @@global.gtid_executed;
set sql_log_bin=0;
insert into nobinlog values (2);
select * from nobinlog;
select @@global.gtid_executed;
set sql_log_bin=1;
insert into nobinlog values (3);
select @@global.gtid_executed;
------

In above test-case nobinlog table is replicated whether it is inside sql_log_bin=0 or 1.
DML statement insert (2) is not replicated and neither is GTID incremented as binlog is not written.

[Sveta Smirnova (svetasmirnova)]

Workaround: wsrep_replicate_myisam=1

[markus_albe (markus-albe)]

The same happens with user management statements; On the same setup I did my initial testing:

node1, with sql_log_bin=1:

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1065
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-2
1 row in set (0.00 sec)

PXC: root@localhost ((none)) > CREATE USER 'demo'@'localhost' IDENTIFIED BY 's3kr3t';
Query OK, 0 rows affected (0.01 sec)

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1318
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec)

PXC: root@localhost ((none)) > SET sql_log_bin=0;
Query OK, 0 rows affected (0.00 sec)

PXC: root@localhost ((none)) > CREATE USER 'demo2'@'localhost' IDENTIFIED BY 's3kr3t';
Query OK, 0 rows affected (0.00 sec)

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1318
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec)

PXC: root@localhost ((none)) > DROP USER 'demo2'@'localhost' ;
Query OK, 0 rows affected (0.00 sec)

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1318
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec)

PXC: root@localhost ((none)) > GRANT ALL PRIVILEGES ON *.* TO 'demo'@'localhost';
Query OK, 0 rows affected (0.01 sec)

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc1-bin.000006
         Position: 1318
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec)

On node2 I ran SHOW MASTER STATUS after each command on node1:

PXC: root@localhost ((none)) > show master status\G
*************************** 1. row ***************************
             File: pxc2-bin.000002
         Position: 863
     Binlog_Do_DB:
 Binlog_Ignore_DB:
Executed_Gtid_Set: f1474806-8db4-ee18-6ad9-c0f4a40f068e:1-3
1 row in set (0.00 sec) ...

[Sveta Smirnova (svetasmirnova)]

Suggested fix: all statements to be not written into binary log if sql_log_bin=0 and the GTID sequence of all nodes will remain in-sync.

[Krunal Bauskar (krunal-bauskar)]

commit 183043e54f41d2dd607bcae5e28fd6dc53b031e8
Author: Krunal Bauskar <email address hidden>
Date: Mon Jul 31 13:11:50 2017 +0530

    - PXC#841: DDL is replicated even when sql_log_bin=0, and GTID is
      incremented in remote node

      sql_log_bin=0 will stop generation of binary logs data.
      In turn it will also stop replication and GTID increment.

      PXC executes DDL through TOI and DML through normal replication.
      Since binary log is not-generated DML replication was already blocked.
      DDL path didn't had a check for sql_log_bin.
      Added the needed check.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXC-841