Bug #82848 Restarting a slave after seeding it with a mysqldump loses it's position
Submitted: 2 Sep 2016 15:02 Modified: 8 Jun 12:07
Reporter: Daniël van Eeden (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: mysqldump Command-line Client Severity:S1 (Critical)
Version:5.7.14 OS:Any
Assigned to:
Tags: GTID

[2 Sep 2016 15:02] Daniël van Eeden
Description:
MySQL loses it's gtid position after a restart when a mysqldump was used to load data.

How to repeat:
On the master:
mysqldump --master-data=2 --all-databases --triggers --routines --events > dump.sql

On the slave:
stop slave; reset slave; reset master; source dump.sql;

mysql> SELECT @@global.gtid_executed, @@global.gtid_purged\G
*************************** 1. row ***************************
@@global.gtid_executed: 1917b868-70fa-11e6-b5ef-f0921c13bca8:1-18699
  @@global.gtid_purged: 1917b868-70fa-11e6-b5ef-f0921c13bca8:1-10877
1 row in set (0.00 sec)

sudo /etc/init.d/mysqld stop
sudo /etc/init.d/mysqld start --skip-slave-start

mysql> SELECT @@global.gtid_executed, @@global.gtid_purged\G
*************************** 1. row ***************************
@@global.gtid_executed: 1917b868-70fa-11e6-b5ef-f0921c13bca8:1-5272:10878-18699
  @@global.gtid_purged: 1917b868-70fa-11e6-b5ef-f0921c13bca8:1-5272

So this is what I think happens:
RESET MASTER empties mysql.gtid_executed
The dump sets GTID_PURGED which puts data in mysql.gtid_executed
Now the dump recreates mysql.gtid_purged with data from the dump

Suggested fix:
Exclude mysql.gtid_executed from the dump
Or make sure the gtid state for all uuid's is written to the binlogs and/or to this table on binlog rotation (then flush master logs would fix this by adding missing entries to mysql.gtid_purged).
[3 Sep 2016 8:16] Daniël van Eeden
Some more details:

Setup with MySQL Sandbox:
make_sandbox 5.7.14 -- --check_port --gtid
make_sandbox 5.7.14 -- --check_port --gtid
Changed prompt in my.sandbox.cnf to indicate instance A or B. 

A:
RESET MASTER;
USE test
CREATE TABLE t1 (id SERIAL);
FLUSH LOGS;
PURGE BINARY LOGS BEFORE NOW();
INSERT INTO t1 VALUES(NULL),(NULL),(NULL);

A mysql > SELECT @@global.gtid_purged, @@global.gtid_executed\G
*************************** 1. row ***************************
  @@global.gtid_purged: 00005715-5714-5714-5714-000000005714:1
@@global.gtid_executed: 00005715-5714-5714-5714-000000005714:1-2
1 row in set (0.00 sec)

A mysql > SELECT * FROM mysql.gtid_executed;
+--------------------------------------+----------------+--------------+
| source_uuid                          | interval_start | interval_end |
+--------------------------------------+----------------+--------------+
| 00005715-5714-5714-5714-000000005714 |              1 |            1 |
+--------------------------------------+----------------+--------------+
1 row in set (0.01 sec)

./my sqldump --all-databases --triggers --routines --events > /tmp/dump.sql

B:
RESET MASTER;
SOURCE /tmp/dump.sql

B mysql > SELECT @@global.gtid_purged, @@global.gtid_executed\G
*************************** 1. row ***************************
  @@global.gtid_purged: 00005715-5714-5714-5714-000000005714:1-2
@@global.gtid_executed: 00005715-5714-5714-5714-000000005714:1-2
1 row in set (0.00 sec)

B mysql > SELECT * FROM mysql.gtid_executed;
+--------------------------------------+----------------+--------------+
| source_uuid                          | interval_start | interval_end |
+--------------------------------------+----------------+--------------+
| 00005715-5714-5714-5714-000000005714 |              1 |            1 |
+--------------------------------------+----------------+--------------+
1 row in set (0.00 sec)

./restart

B mysql > SELECT @@global.gtid_purged, @@global.gtid_executed\G
*************************** 1. row ***************************
  @@global.gtid_purged: 00005715-5714-5714-5714-000000005714:1
@@global.gtid_executed: 00005715-5714-5714-5714-000000005714:1
1 row in set (0.00 sec)

B mysql > SELECT * FROM mysql.gtid_executed;
+--------------------------------------+----------------+--------------+
| source_uuid                          | interval_start | interval_end |
+--------------------------------------+----------------+--------------+
| 00005715-5714-5714-5714-000000005714 |              1 |            1 |
+--------------------------------------+----------------+--------------+
1 row in set (0.00 sec)

From /tmp/dump.sql:

...
SET @@SESSION.SQL_LOG_BIN= 0;
...
SET @@GLOBAL.GTID_PURGED='00005715-5714-5714-5714-000000005714:1-2';
...
DROP TABLE IF EXISTS `gtid_executed`;
...
CREATE TABLE `gtid_executed` (
...
INSERT INTO `gtid_executed` VALUES ('00005715-5714-5714-5714-000000005714',1,1);
...
SET @@SESSION.SQL_LOG_BIN = @MYSQLDUMP_TEMP_LOG_BIN;
[3 Sep 2016 9:59] Umesh Shastry
Hello Daniël,

Thank you for the report.
Observed this with 5.7.14 build.

Thanks,
Umesh
[3 Sep 2016 10:00] Umesh Shastry
test results

Attachment: 82848.results (application/octet-stream, text), 21.56 KiB.

[3 Sep 2016 10:13] Daniël van Eeden
Workaround: 

add '--ignore-table=mysql.gtid_executed' to mysqldump options or add this to my.cnf:

========================
[mysqldump]
ignore-table=mysql.gtid_executed
========================

Fix: https://github.com/mysql/mysql-server/pull/94
[3 Sep 2016 10:20] Daniël van Eeden
Patch https://github.com/mysql/mysql-server/pull/94

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: 0001-Don-t-dump-mysql.gtid_executed.patch (text/x-patch), 1.20 KiB.

[3 Sep 2016 10:28] Umesh Shastry
Bug #81692 marked as duplicate of this one
[3 Sep 2016 11:01] Daniël van Eeden
Changing category to reflect that this is a mysqldump bug.
Changed severity to S1 as this issue might not be noticed until when you restart a slave and then recovering might be difficult. 

Related:
Bug #71565 	Please report full GTID state when stopping / start a slave
[4 Sep 2016 15:47] Daniël van Eeden
A MTR test case.

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: 0002-Add-test-case-for-Bug-82848.patch (text/x-patch), 1.78 KiB.

[8 Jun 12:07] Jon Stephens
Documented fix in the MySQL 5.7.19 and 8.0.2 changelogs, as follows:

    MySQL lost its GTID position following a restart when a dump
    from mysqldump had been used to load data.

    To keep this problem from occurring, the mysql.gtid_executed
    table is now excluded from dumps by mysqldump automatically.

Closed.