Bug #85221 Group Replication : Error while adding instance in group.
Submitted: 28 Feb 2017 8:51 Modified: 11 Jul 2017 11:44
Reporter: lalit Choudhary Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Packaging Severity:S3 (Non-critical)
Version:5.7.17 OS:Red Hat
Assigned to: CPU Architecture:Any
Tags: group replication

[28 Feb 2017 8:51] lalit Choudhary
Description:
While doing testing for Group replication for single primary mode by referring https://dev.mysql.com/doc/refman/5.7/en/group-replication-deploying-in-single-primary-mode...

Getting following error while adding an instance in Group replication and START GROUP_REPLICATION fails with following error in error log,

[ERROR] Plugin group_replication reported: 'This member has more executed transactions than those present in the group. Local transactions: 19500be1-fd87-11e6-982c-0050560525da:1-2 > Group transactions: 64100a82-fccb-11e6-9ead-00505605efff:1-10'
[ERROR] Plugin group_replication reported: 'The member contains transactions not present in the group. The member will now exit the group.'

I know that we can enable group_replication_allow_local_disjoint_gtids_join but at first place it should not throw error.

Here Problem is: 

When we install MySQL using RPM pakages, by default it will generate default password for first-time login into mysql and after login using this password we have to reset this password in order to proceed further. For this we have to execute ALTER USER statement which will get logged in Binary log and this cause an issue for transaction count mismatch while starting Group replication.

Detail log attached. 

How to repeat:
While doing testing for Group replication for single primary mode by referring https://dev.mysql.com/doc/refman/5.7/en/group-replication-deploying-in-single-primary-mode...

Got some issues/error while adding an instance in Group replication.

A per document I have deployed main instance with given instructions successfully. Following is the my.cnf configuration for main instance,

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

# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0

log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

server_id=104
skip-name-resolve
bind-address=0.0.0.0

# General replication configuration
master_info_repository = TABLE
relay_log_info_repository = TABLE
log-bin=mysql-bin104
relay-log=relay-bin104
relay_log_recovery= on
log-slave-updates=1
#expire_logs_days=15
gtid-mode=on
enforce-gtid-consistency=1
binlog_format=row
binlog_checksum=NONE
# Group  replication configuration
transaction_write_set_extraction=XXHASH64
loose-group_replication_group_name="64100a82-fccb-11e6-9ead-00505605efff"
loose-group_replication_start_on_boot=off
loose-group_replication_local_address= "192.168.2.104:3307"
loose-group_replication_group_seeds= "192.168.2.104:3307,192.168.2.103:3308,192.168.2.102:3309,192.168.2.101:3310"
loose-group_replication_bootstrap_group= off

[mysql]
socket = /var/lib/mysql/mysql.sock

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

NOTE: At this point, the group has one member in it, Main server, which has some data in it. let's add a second instance in a group.

Problem Start when I tried to add a second instance in group replication as follows,

Step:1 
Install mysql using RPM pakages.
 
Following is my.cnf configuration:

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

# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0

log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

port=3306
server_id=103
skip-name-resolve
bind-address=0.0.0.0

# General replication configuration
 master_info_repository = TABLE
 relay_log_info_repository = TABLE
 log-bin=mysql-bin103
 relay-log=relay-bin103
 relay_log_recovery= on
 log-slave-updates=1
 #expire_logs_days=15
 gtid-mode=on
 enforce-gtid-consistency=1
 binlog_format=row
 binlog_checksum=NONE

 # Group  replication configuration
 transaction_write_set_extraction=XXHASH64
 loose-group_replication_group_name="64100a82-fccb-11e6-9ead-00505605efff"
 loose-group_replication_start_on_boot=off
 loose-group_replication_local_address= "192.168.2.103:3308"
 loose-group_replication_group_seeds= "192.168.2.104:3307,192.168.2.103:3308,192.168.2.102:3309,192.168.2.101:3310"
 loose-group_replication_bootstrap_group= off

 [mysql]
 socket = /var/lib/mysql/mysql.sock

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

STEP 2:

- Login to mysql with default generated password in mysql server log (log-error).
- Set root@localhost password using ALTER USER.
- Executed follwing cmds for group replication setup:
mysql> SET SQL_LOG_BIN=0;
Query OK, 0 rows affected (0.00 sec)

mysql> CREATE USER rpl_user@'%' IDENTIFIED BY 'Rpl_usr@114';
Query OK, 0 rows affected (0.00 sec)

mysql> GRANT REPLICATION SLAVE ON *.* TO rpl_user@'%';
Query OK, 0 rows affected (0.00 sec)

mysql> FLUSH PRIVILEGES;
Query OK, 0 rows affected (0.00 sec)

mysql> SET SQL_LOG_BIN=1;
Query OK, 0 rows affected (0.00 sec)

mysql> CHANGE MASTER TO MASTER_USER='rpl_user', MASTER_PASSWORD='Rpl_usr@114' FOR CHANNEL 'group_replication_recovery';
Query OK, 0 rows affected, 2 warnings (0.01 sec)

mysql> INSTALL PLUGIN group_replication SONAME 'group_replication.so';
Query OK, 0 rows affected (0.01 sec)

mysql> START GROUP_REPLICATION;
ERROR 3092 (HY000): The server is not configured properly to be an active member of the group. Please see more details on error log.

mysql> SELECT * FROM performance_schema.replication_group_members;
+---------------------------+--------------------------------------+--------------+-------------+--------------+
| CHANNEL_NAME              | MEMBER_ID                            | MEMBER_HOST  | MEMBER_PORT | MEMBER_STATE |
+---------------------------+--------------------------------------+--------------+-------------+--------------+
| group_replication_applier | 19500be1-fd87-11e6-982c-0050560525da | VM-100351267 |        3306 | OFFLINE      |
+---------------------------+--------------------------------------+--------------+-------------+--------------+
1 row in set (0.00 sec)

After Looking at error log i found this error,

[ERROR] Plugin group_replication reported: 'This member has more executed transactions than those present in the group. Local transactions: 19500be1-fd87-11e6-982c-0050560525da:1-2 > Group transactions: 64100a82-fccb-11e6-9ead-00505605efff:1-10'
[ERROR] Plugin group_replication reported: 'The member contains transactions not present in the group. The member will now exit the group.'

Binlog events:

mysql> show binlog events in 'mysql-bin103.000001';
+---------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------+
| Log_name            | Pos | Event_type     | Server_id | End_log_pos | Info                                                              |
+---------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------+
| mysql-bin103.000001 |   4 | Format_desc    |       103 |         123 | Server ver: 5.7.17-log, Binlog ver: 4                             |
| mysql-bin103.000001 | 123 | Previous_gtids |       103 |         150 |                                                                   |
| mysql-bin103.000001 | 150 | Gtid           |       103 |         211 | SET @@SESSION.GTID_NEXT= '19500be1-fd87-11e6-982c-0050560525da:1' |
| mysql-bin103.000001 | 211 | Query          |       103 |         278 | BEGIN                                                             |
| mysql-bin103.000001 | 278 | Table_map      |       103 |         329 | table_id: 62 (mysql.plugin)                                       |
| mysql-bin103.000001 | 329 | Write_rows     |       103 |         401 | table_id: 62 flags: STMT_END_F                                    |
| mysql-bin103.000001 | 401 | Xid            |       103 |         428 | COMMIT /* xid=3949 */                                             |
| mysql-bin103.000001 | 428 | Stop           |       103 |         447 |                                                                   |
+---------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------+
8 rows in set (0.00 sec)

mysql> show binlog events in 'mysql-bin103.000002';
+---------------------+-----+----------------+-----------+-------------+----------------------------------------------------------------------------------------------------------------------+
| Log_name            | Pos | Event_type     | Server_id | End_log_pos | Info                                                                                                                 |
+---------------------+-----+----------------+-----------+-------------+----------------------------------------------------------------------------------------------------------------------+
| mysql-bin103.000002 |   4 | Format_desc    |       103 |         123 | Server ver: 5.7.17-log, Binlog ver: 4                                                                                |
| mysql-bin103.000002 | 123 | Previous_gtids |       103 |         190 | 19500be1-fd87-11e6-982c-0050560525da:1                                                                               |
| mysql-bin103.000002 | 190 | Gtid           |       103 |         251 | SET @@SESSION.GTID_NEXT= '19500be1-fd87-11e6-982c-0050560525da:2'                                                    |
| mysql-bin103.000002 | 251 | Query          |       103 |         426 | ALTER USER 'root'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*7BB96B4D3E986612D96E53E62DBE9A38AAA40A5A' |
| mysql-bin103.000002 | 426 | Stop           |       103 |         445 |                                                                                                                      |
+---------------------+-----+----------------+-----------+-------------+----------------------------------------------------------------------------------------------------------------------+
5 rows in set (0.00 sec)

Suggested fix:
Need to fix this issue for MySQL package installation.
[28 Feb 2017 8:52] lalit Choudhary
steps and log file

Attachment: group_replication_step_error_logs.txt (text/plain), 12.61 KiB.

[7 Mar 2017 9:28] Bogdan Kecman
Hi,

Thanks for your report. I think this is more "documentation" bug then a group replication bug, as it's expected that you should configure your access data (user/pass combo's) before you turn on the replication; but it's not written anywhere so at least that should be documented, if not changed.

kind regards
Bogdan
[8 Mar 2017 11:12] Lalit Choudhary
Initially, we should able set starting point from where group replication start.

No matter what will do this error will always occur for RPM package installation.

How to solve this:

After getting this error we have SET GTID from appropriate value using SET GTID PURGE ='<executed-gtid>' option.

Did you tried it to replicated this issue using rpm package install? I'm sure that it will throw a same error for group replication setup on MySQL rpm installtions.
___________

About documentation if above is the case we should add note for such setups that, user need to SET starting GTID point if they executed SQL statements before setting up group replication to avoid such errors.
[11 Jul 2017 11:44] Erlend Dahl
[8 Jun 2017 10:57] Jon Stephens

Documented fix as follows int he MySQL 5.7.19 and 8.0.2 changelogs:

    When first starting the MySQL server following an installation
    from RPM, passwword validation plugin is activated by default
    (true only for RPM installations). If binary logging was already
    enabled at this time, the activation was logged, even though
    plugin activations should never be recorded in the binary log.

Closed.