一个比较诡异的基于GTID复制的问题

Question

在虚拟机测试GTID复制的过程中，从主库做的操作无法传输到从库，排查过程如下：

1、在从库上执行show slave status\G,提示如下（两个线程都是正常的）：

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.1.107
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000003
          Read_Master_Log_Pos: 745
               Relay_Log_File: relay_log.000002
                Relay_Log_Pos: 408
        Relay_Master_Log_File: mysql-bin.000003
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
              Replicate_Do_DB: 
          Replicate_Ignore_DB: 
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 0
                   Last_Error: 
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 745
              Relay_Log_Space: 606
              Until_Condition: None
               Until_Log_File: 
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
           Master_SSL_CA_File: 
           Master_SSL_CA_Path: 
              Master_SSL_Cert: 
            Master_SSL_Cipher: 
               Master_SSL_Key: 
        Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 0
               Last_SQL_Error: 
  Replicate_Ignore_Server_Ids: 
             Master_Server_Id: 107
                  Master_UUID: 7ada1b71-5ecd-11e5-b7b7-000c291231a4
             Master_Info_File: mysql.slave_master_info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Slave has read all relay log; waiting for the slave I/O thread to update it
           Master_Retry_Count: 86400
                  Master_Bind: 
      Last_IO_Error_Timestamp: 
     Last_SQL_Error_Timestamp: 
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 
            Executed_Gtid_Set: 7ada1b71-5ecd-11e5-b7b7-000c291231a4:1-8
                Auto_Position: 1
1 row in set (0.00 sec)

2、查看从库的错误日志，发现有如下提示：

[root@host126 ~]# tail -n200 /var/log/mysqld.log 

#……（之前的省略）
2016-09-05 10:40:37 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2016-09-05 10:40:37 2941 [Note] Plugin 'FEDERATED' is disabled.
2016-09-05 10:40:37 2941 [Note] InnoDB: The InnoDB memory heap is disabled
2016-09-05 10:40:37 2941 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-09-05 10:40:37 2941 [Note] InnoDB: Compressed tables use zlib 1.2.3
2016-09-05 10:40:37 2941 [Note] InnoDB: Using CPU crc32 instructions
2016-09-05 10:40:37 2941 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2016-09-05 10:40:37 2941 [Note] InnoDB: Completed initialization of buffer pool
2016-09-05 10:40:37 2941 [Note] InnoDB: Highest supported file format is Barracuda.
2016-09-05 10:40:37 2941 [Note] InnoDB: 128 rollback segment(s) are active.
2016-09-05 10:40:37 2941 [Note] InnoDB: Waiting for purge to start
2016-09-05 10:40:38 2941 [Note] InnoDB: 5.6.11 started; log sequence number 1869370
2016-09-05 10:40:38 2941 [Note] Server hostname (bind-address): '*'; port: 3306
2016-09-05 10:40:38 2941 [Note] IPv6 is available.
2016-09-05 10:40:38 2941 [Note]   - '::' resolves to '::';
2016-09-05 10:40:38 2941 [Note] Server socket created on IP: '::'.
2016-09-05 10:40:38 2941 [Note] Slave I/O thread: Start asynchronous replication to master 'repl@192.168.1.107:3306' in log 'mysql-bin.000002' at position 471
2016-09-05 10:40:38 2941 [Warning] Storing MySQL user name or password information in the master.info repository is not secure and is therefore not recommended. Please see the MySQL Manual for more about this issue and possible alternatives.
2016-09-05 10:40:38 2941 [Note] Slave I/O thread: connected to master 'repl@192.168.1.107:3306',replication started in log 'mysql-bin.000002' at position 471
2016-09-05 10:40:38 2941 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000002' at position 471, relay log '/var/log/relay/relay_log.000003' position: 408
2016-09-05 10:40:38 2941 [Note] Event Scheduler: Loaded 0 events
2016-09-05 10:40:38 2941 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.6.11-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Source distribution
160905 10:40:39 mysqld_safe A mysqld process already exists
2016-09-05 10:45:21 2941 [Note] Error reading relay log event: slave SQL thread was killed
2016-09-05 10:45:21 2941 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013)
2016-09-05 10:45:21 2941 [Note] Slave I/O thread killed while reading event
2016-09-05 10:45:21 2941 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000003', position 745
2016-09-05 10:46:00 2941 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''. New state master_host='192.168.1.107', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''.
2016-09-05 10:46:15 2941 [Note] Slave I/O thread: Start asynchronous replication to master 'repl@192.168.1.107:3306' in log 'FIRST' at position 4
2016-09-05 10:46:15 2941 [Warning] Storing MySQL user name or password information in the master.info repository is not secure and is therefore not recommended. Please see the MySQL Manual for more about this issue and possible alternatives.
2016-09-05 10:46:15 2941 [Note] Slave I/O thread: connected to master 'repl@192.168.1.107:3306',replication started in log 'FIRST' at position 4
2016-09-05 10:46:15 2941 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log '/var/log/relay/relay_log.000001' position: 4

针对错误日志里面的ERROR,百度了多次没有找到有效的解决办法。

劳烦老师帮忙看看是什么原因，为何从库的IO线程和SQL线程都是yes，主库的操作却无法同步到从库上来？谢谢！

Answer 1

sqlercn 2016-09-05 16:20:38

把slave进程停了重启一下看看。

• 提问者 爱学习的程序员2019 #1

  多谢老师，我在从库执行了如下操作：
  stop slave;
  service mysqld stop;
  service mysqld start;
  重新连接之后 发现可以正常复制了，但故障期间的主库的操作仍然没有被从库执行，导致这一段时间主库的操作没有被同步。请问老师有什么解决办法吗？

• sqlercn 回复 提问者 爱学习的程序员2019 #2

  找出差异数据，在从库中恢复差异数据即可。

• 提问者 爱学习的程序员2019 回复 sqlercn #3

  老师，具体怎么恢复啊？用什么命令或工具？如果故障期间产生了上万甚至百万、千万的数据，那应该不会手动去恢复吧？

点开查看后面2条评论

Answer 2

sqlercn 2016-09-05 13:46:39

看show slave status 的结果主从复制应该是正常的才对呀。如果不能同步的话，看看show master status 以及master 上的show processlist 看看进程是否正常？

• 提问者 爱学习的程序员2019 #1

  这两项一切正常，但主库的操作仍然没有被从库执行。所以这个问题是非常非常的诡异。