Bug #90146 If GNO exhausts GR hits with Assert `!executed_gtids.contains_gtid(gtid)'
Submitted: 20 Mar 2018 18:57 Modified: 21 Jun 2018 9:17
Reporter: Narendra Singh Chauhan Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Group Replication Severity:S3 (Non-critical)
Version:8.0.11 OS:Any
Assigned to: CPU Architecture:Any

[20 Mar 2018 18:57] Narendra Singh Chauhan
Description:
Scenario: Test that GR instructs to rollback the current transaction when GNO is exhausted.
Observation: GR is hitting with ASSERT instead of ER_TRANSACTION_ROLLBACK_DURING_COMMIT.

Note:-
1. Without GR (normal GTID enabled server) we are hitting proper ABORT_SERVER action.
"mysqltest: At line 15: query 'CREATE TABLE tab1 (a INT PRIMARY KEY)' failed: 1598: Binary logging not possible. Message: An error occurred during flush stage of the commit. 'binlog_error_action' is set to 'ABORT_SERVER'. Hence aborting the server."

"2018-03-20T18:00:25.651288Z 2 [ERROR] /Narendra/mysql_work/git_repo/mysql-5.7/install/bin/mysqld: Binary logging not possible. Message: An error occurred during flush stage of the commit. 'binlog_error_action' is set to 'ABORT_SERVER'. Hence aborting the server.
18:00:25 UTC - mysqld got signal 6 ;"

2. On 5.7.22: we are hitting proper ER_TRANSACTION_ROLLBACK_DURING_COMMIT if GNO is exhausted.
"CREATE TABLE t1 (a INT PRIMARY KEY)' failed: 3101: Plugin instructed the server to rollback the current transaction."

"2018-03-20T18:31:16.192469Z 11 [ERROR] Plugin group_replication reported: 'Impossible to generate Global Transaction Identifier: the integer component reached the maximal value. Restart the group with a new group_replication_group_name.'"

3. But, on 8.0.11 (8.0.5) I can see that we are hitting with ASSERTION failure.
======
CURRENT_TEST: group_replication.gr_gno_assert
mysqltest: At line 16: query 'CREATE TABLE t1 (a INT PRIMARY KEY)' failed: 2013: Lost connection to MySQL server during query
safe_process[28243]: Child process: 28244, exit: 1
....
....
2018-03-20T18:40:16.507332Z 12 [System] [MY-010916] @@GLOBAL.GTID_PURGED was changed from '' to 'aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa:2-9223372036854775806'.
2018-03-20T18:40:16.507365Z 12 [System] [MY-010917] @@GLOBAL.GTID_EXECUTED was changed from 'aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa:1' to 'aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa:1-9223372036854775806'.
mysqld: /Narendra/mysql_work/git_repo/mysql-8.0/sql/rpl_gtid_state.cc:81: enum_return_status Gtid_state::acquire_ownership(THD*, const Gtid&): Assertion `!executed_gtids.contains_gtid(gtid)' failed.
18:40:17 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=8
max_threads=151
thread_count=10
connection_count=6
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 67868 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f741002b800
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f749012ed38 thread_stack 0x46000
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(my_print_stacktrace(unsigned char*, unsigned long)+0x55) [0x40ca059]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(handle_fatal_signal+0x424) [0x2e30a55]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390) [0x7f749dc82390]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x38) [0x7f749c377428]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a) [0x7f749c37902a]
/lib/x86_64-linux-gnu/libc.so.6(+0x2dbd7) [0x7f749c36fbd7]
/lib/x86_64-linux-gnu/libc.so.6(+0x2dc82) [0x7f749c36fc82]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(Gtid_state::acquire_ownership(THD*, Gtid const&)+0xab) [0x3c8557f]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(Gtid_state::generate_automatic_gtid(THD*, int, long long, int*)+0x273) [0x3c86b9b]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(MYSQL_BIN_LOG::assign_automatic_gtids_to_flush_group(THD*)+0x121) [0x3cc9875]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(MYSQL_BIN_LOG::process_flush_stage_queue(unsigned long long*, bool*, THD**)+0x12c) [0x3ce0c42]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(MYSQL_BIN_LOG::ordered_commit(THD*, bool, bool)+0x4f7) [0x3ce23cf]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(MYSQL_BIN_LOG::commit(THD*, bool)+0xe39) [0x3ce089d]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(ha_commit_trans(THD*, bool, bool)+0x7cc) [0x2fa9f11]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(trans_commit_implicit(THD*, bool)+0x17c) [0x2ddd909]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(mysql_create_table(THD*, TABLE_LIST*, HA_CREATE_INFO*, Alter_info*)+0x9b6) [0x2d346c1]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(Sql_cmd_create_table::execute(THD*)+0xb70) [0x320e508]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(mysql_execute_command(THD*, bool)+0x23a3) [0x2c8fc85]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(mysql_parse(THD*, Parser_state*)+0x65e) [0x2c9573c]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(dispatch_command(THD*, COM_DATA const*, enum_server_command)+0x12ab) [0x2c8b2e2]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld(do_command(THD*)+0x484) [0x2c89c97]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld() [0x2e1eb07]
/Narendra/mysql_work/git_repo/mysql-8.0/install/bin/mysqld() [0x477b44e]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba) [0x7f749dc786ba]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f749c4493dd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f741028b9d8): CREATE TABLE t1 (a INT PRIMARY KEY)
Connection ID (thread ID): 12
Status: NOT_KILLED

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
safe_process[28171]: Child process: 28172, killed by signal: 6
----------SERVER LOG END-------------
======

How to repeat:
Details:-
=========
MySQL Version checked: 8.0.11

Steps to repro:-
================
Run command: $ ./mtr group_replication.gr_gno_assert.test
Where,
$ cat suite/group_replication/t/gr_gno_assert.test
##############################################################################
# Validate that GR behaves properly when group GNOs are exhausted.
##############################################################################
--let $group_replication_group_name= aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa
--source include/have_group_replication_plugin.inc
--let $rpl_skip_group_replication_start= 1
--source include/group_replication.inc

--let $rpl_connection_name= server1
--source include/rpl_connection.inc
# To test without GR being started, uncomment below lines.
#--let $server_uuid= query_get_value(SELECT @@SERVER_UUID, @@SERVER_UUID, 1)
#--eval SET GLOBAL GTID_PURGED= "$server_uuid:1-9223372036854775806"
#--echo
#--echo # ABORT_SERVER HERE
#CREATE TABLE tab1 (a INT PRIMARY KEY);

--source include/start_and_bootstrap_group_replication.inc
SET GLOBAL GTID_PURGED= "+aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa:2-9223372036854775806";

--echo
--echo # ASSERTION FAILURE HERE
CREATE TABLE t1 (a INT PRIMARY KEY);

DROP TABLE t1;

--source include/group_replication_end.inc
[21 Jun 2018 9:17] David Moss
Posted by developer:
 
Thank you for your feedback, this has been fixed in upcoming versions and the following was added to the 8.0.12 changelog:
The gtid_purged variable contains the binary log events that have been purged from the log by the server. when running the group replication plugin this variable should never be modified, but it was possible.  Now the variable cannot be modified when Group Replication is running.