MySQL Bugs: #78749: Assertion `!flags.finalized' failed with group replication plugin

Bug #78749	Assertion `!flags.finalized' failed with group replication plugin
Submitted:	8 Oct 2015 6:25	Modified:	3 Dec 2015 14:05
Reporter:	Shahriyar Rzayev	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Group Replication	Severity:	S1 (Critical)
Version:	0.5.0-dmr	OS:	Ubuntu (14.04)
Assigned to:		CPU Architecture:	Any

Description:
The procedures i did is quite straightforward i followed:

http://mysqlhighavailability.com/getting-started-with-mysql-group-replication/

The one thing is i created a connection error situation by not creating replication user in node2. After starting group replication on node2, it states noted as RECOVERING.

node1 [localhost] {msandbox} (test) > SELECT * FROM performance_schema.replication_group_members\G
*************************** 1. row ***************************
CHANNEL_NAME: group_replication_applier
   MEMBER_ID: 00008379-1111-1111-1111-111111111111
 MEMBER_HOST: shrzayev
 MEMBER_PORT: 8379
MEMBER_STATE: ONLINE
*************************** 2. row ***************************
CHANNEL_NAME: group_replication_applier
   MEMBER_ID: 00008380-2222-2222-2222-222222222222
 MEMBER_HOST: shrzayev
 MEMBER_PORT: 8380
MEMBER_STATE: RECOVERING
2 rows in set (0,00 sec)

But due to connection problem it will leave group as it says in error log of node2:

2015-10-08T06:13:10.064757Z 6 [ERROR] Plugin group_replication reported: 'There was an error when connecting to the donor server. Check group r
eplication recovery's connection credentials.'
2015-10-08T06:13:10.064795Z 6 [ERROR] Plugin group_replication reported: 'Maximum number of retries when trying to connect to a donor reached. 
Aborting group replication recovery.'
2015-10-08T06:13:10.064818Z 6 [Note] Plugin group_replication reported: 'Terminating existing group replication donor connection and purging th
e corresponding logs.'
2015-10-08T06:13:10.064928Z 8 [Note] Error reading relay log event for channel 'group_replication_recovery': slave SQL thread was killed
2015-10-08T06:13:10.197356Z 6 [ERROR] Plugin group_replication reported: 'Fatal error during the Recovery process of Group Replication. The ser
ver will leave the group.'

After leaving the group if you try to change again global variables:

node2 [localhost] {msandbox} ((none)) > SET GLOBAL group_replication_group_name= "8a94f357-aab4-11df-86ab-c80aa9429562";
ERROR 1231 (42000): Variable 'group_replication_group_name' can't be set to the value of '8a94f357-aab4-11df-86ab-c80aa9429562'
node2 [localhost] {msandbox} ((none)) >     SET GLOBAL group_replication_recovery_user='rpl_user';
Query OK, 0 rows affected (0,00 sec)

node2 [localhost] {msandbox} ((none)) >     SET GLOBAL group_replication_recovery_password='rpl_pass';
Query OK, 0 rows affected (0,00 sec)

node2 [localhost] {msandbox} ((none)) >     SET GLOBAL group_replication_recovery_retry_count= 2;
Query OK, 0 rows affected (0,00 sec)

node2 [localhost] {msandbox} ((none)) >     SET GLOBAL group_replication_recovery_reconnect_interval= 120;
Query OK, 0 rows affected (0,00 sec)

And then if you try to run create user statement:

node2 [localhost] {msandbox} ((none)) > CREATE USER 'rpl_user'@'%' IDENTIFIED BY 'rpl_pass';
ERROR 2013 (HY000): Lost connection to MySQL server during query

From error log:

2015-10-08T06:14:03.522050Z 10 [ERROR] Plugin group_replication reported: 'The group name cannot be changed when Group Replication is running'
2015-10-08T06:14:21.240476Z 10 [ERROR] Plugin group_replication reported: 'Transaction cannot be executed while Group Replication is OFFLINE. C
heck for errors and restart the plugin'
2015-10-08T06:14:21.240518Z 10 [ERROR] Run function 'before_commit' in plugin 'group_replication' failed
mysqld: /home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server/sql/binlog.cc:1320: int binlog_cache_data::finalize(THD*, L
og_event*): Assertion `!flags.finalized' failed.
06:14:21 UTC - mysqld got signal 6 ;

How to repeat:
1. Do steps from blog post mentioned in description.
2. Create replication user only on node1 but not on node2(create connection error situation)
3. Rerun set global variables on node2.
4. Try to create replication user on node2.

Suggested fix:
no idea.

Full error log output:

stack_bottom = 7f14cd896e10 thread_stack 0x40000
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(my_print_stacktrace+0x38)[0x178393b]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(handle_fatal_signal+0x3f6)[0xddb755]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f14f8156340]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39)[0x7f14f7597cc9]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f14f759b0d8]
/lib/x86_64-linux-gnu/libc.so.6(+0x2fb86)[0x7f14f7590b86]
/lib/x86_64-linux-gnu/libc.so.6(+0x2fc32)[0x7f14f7590c32]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_ZN17binlog_cache_data8finalizeEP3THDP9Log_e
vent+0x7e)[0x16d9f5c]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_ZN22binlog_stmt_cache_data8finalizeEP3THD+0
x61)[0x16d8e65]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_ZN13MYSQL_BIN_LOG30write_binlog_and_commit_
engineEP3THDb+0x594)[0x16ea248]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_ZN13MYSQL_BIN_LOG6commitEP3THDb+0xad)[0x16e
9c03]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_Z21trans_commit_implicitP3THD+0x1bb)[0x1550
d73]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_Z30acl_end_trans_and_close_tablesP3THDb+0x9
4)[0xdf94ac]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_Z17mysql_create_userP3THDR4ListI11st_lex_us
erEb+0x67e)[0x15e455c]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_Z21mysql_execute_commandP3THD+0x41d8)[0x144
bfb3]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x552)[0
x14507e6]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_Z16dispatch_commandP3THDP8COM_DATA19enum_se
rver_command+0xdca)[0x1445bea]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(_Z10do_commandP3THD+0x4b2)[0x1444932]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(handle_connection+0x1c4)[0x157e9ae]
/home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld(pfs_spawn_thread+0x160)[0x1b9f47e]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7f14f814e182]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f14f765b47d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f145c066f20): CREATE USER 'rpl_user'@'%' IDENTIFIED BY 'rpl_pass'
Connection ID (thread ID): 10
Status: NOT_KILLED

And mysql.user table is crashed here:

node2 [localhost] {msandbox} ((none)) > drop user 'rpl_user'@'%';
ERROR 126 (HY000): Incorrect key file for table './mysql/user.MYI'; try to repair it

2015-10-08T06:38:05.389760Z 2 [ERROR] /home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server.build/5.7.8/bin/mysqld: Incorrect key file for table './mysql/user.MYI'; try to repair it
2015-10-08T06:38:05.389814Z 2 [ERROR] Got an error from thread_id=2, /home/sh/Sandboxes/mysql-group-replication-0.5.0-dmr/BIN/BUILD/mysql-server/storage/myisam/mi_write.c:223
2015-10-08T06:38:05.389836Z 2 [ERROR] MySQL thread id 2, OS thread handle 140493096765184, query id 9 localhost msandbox System lock
CREATE USER 'rpl_user'@'%' IDENTIFIED BY 'rpl_pass'

Hi Shahriyar,

You have an eye for finding open issues :)
So what happened is that on server 2 recovery failed but the plugin is still running. 
As so, it will try to prevent the execution of queries by the user, because he may think the plugin is online when it isn't.

Thing is... this not always works, and that what happened for your 
CREATE USER 'rpl_user'@'%' IDENTIFIED BY 'rpl_pass';

When recovery fails, you should do a "stop group_replication" first to stop the plugin.
Only then you can execute queries on that server. 

As usual, I can only say this is known issue and we are working on ways to solve it. 

Thanks again for pointing stress points for new users.

Thanks for your feedback. This has been fixed in an upcoming version. Note that labs releases do not have a change log documented.