标签归档:MySQL Replication

[MySQL FAQ]系列 — MySQL复制中slave延迟监控

在MySQL复制环境中,我们通常只根据 Seconds_Behind_Master 的值来判断SLAVE的延迟。这么做大部分情况下尚可接受,但并不够准确,而应该考虑更多因素。

首先,我们先看下SLAVE的状态:

yejr@imysql.com [(none)]> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
***
Master_Log_File: mysql-bin.000327
Read_Master_Log_Pos: 668711237
Relay_Log_File: mysql-relay-bin.002999
Relay_Log_Pos: 214736858
Relay_Master_Log_File: mysql-bin.000327
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
***
Skip_Counter: 0
Exec_Master_Log_Pos: 654409041
Relay_Log_Space: 229039311
***
Seconds_Behind_Master: 3296
***

可以看到 Seconds_Behind_Master 的值是 3296,也就是SLAVE至少延迟了 3296 秒。

我们再来看下SLAVE上的2个REPLICATION进程状态:

yejr@imysql.com [(none)]> show full processlist\G
*************************** 1. row ***************************
Id: 6
User: system user
Host:
db: NULL
Command: Connect
Time: 22005006
State: Waiting for master to send event
Info: NULL
*************************** 2. row ***************************
Id: 7
User: system user
Host:
db: NULL
Command: Connect
Time: 3293
State: Updating
Info: UPDATE ** SET ** WHERE **

可以看到SQL线程一直在执行UPDATE操作,注意到 Time 的值是 3293,看起来像是这个UPDATE操作执行了3293秒,一个普通的SQL而已,肯定不至于需要这么久。
实际上,在REPLICATION进程中,Time 这列的值可能有几种情况:
1、SQL线程当前执行的binlog(实际上是relay log)中的timestamp和IO线程最新的timestamp的差值,这就是通常大家认为的 Seconds_Behind_Master 值,并不是某个SQL的实际执行耗时;
2、SQL线程当前如果没有活跃SQL在执行的话,Time值就是SQL线程的idle time;

而IO线程的Time值则是该线程自从启动以来的总时长(多少秒),如果系统时间在IO线程启动后发生修改的话,可能会导致该Time值异常,比如变成负数,或者非常大。

来看下面几个状态:

#设置pager,只查看关注的几个status值
yejr@imysql.com [(none)]> pager cat | egrep -i 'system user|Exec_Master_Log_Pos|Seconds_Behind_Master|Read_Master_Log_Pos'

#这是没有活跃SQL的情况,Time值是idle time,并且 Seconds_Behind_Master 为 0
yejr@imysql.com [(none)]> show processlist; show slave status\G
| 6 | system user | | NULL | Connect | 22004245 | Waiting for master to send event | NULL |
| 7 | system user | | NULL | Connect | 13 | Has read all relay log;**
Read_Master_Log_Pos: 445167889
Exec_Master_Log_Pos: 445167889
Seconds_Behind_Master: 0

#和上面一样
yejr@imysql.com [(none)]> show processlist; show slave status\G
| 6 | system user | | NULL | Connect | 22004248 | Waiting for master to send event | NULL |
| 7 | system user | | NULL | Connect | 16 | Has read all relay log;**
Read_Master_Log_Pos: 445167889
Exec_Master_Log_Pos: 445167889
Seconds_Behind_Master: 0

#这时有活跃SQL了,Time值是和 Seconds_Behind_Master 一样,即SQL线程比IO线程“慢”了1秒
yejr@imysql.com [(none)]> show processlist; show slave status\G
| 6 | system user | | NULL | Connect | 22004252 | Waiting for master to send event | NULL |
| 7 | system user | | floweradmin | Connect | 1 | Updating | update **
Read_Master_Log_Pos: 445182239
Exec_Master_Log_Pos: 445175263
Seconds_Behind_Master: 1

#和上面一样
yejr@imysql.com [(none)]> show processlist; show slave status\G
| 6 | system user | | NULL | Connect | 22004254 | Waiting for master to send event | NULL |
| 7 | system user | | floweradmin | Connect | 1 | Updating | update **
Read_Master_Log_Pos: 445207174
Exec_Master_Log_Pos: 445196837
Seconds_Behind_Master: 1

好了,最后我们说下如何正确判断SLAVE的延迟情况:
1、首先看 Relay_Master_Log_FileMaster_Log_File 是否有差异;
2、如果Relay_Master_Log_FileMaster_Log_File 是一样的话,再来看Exec_Master_Log_PosRead_Master_Log_Pos 的差异,对比SQL线程比IO线程慢了多少个binlog事件;
3、如果Relay_Master_Log_FileMaster_Log_File 不一样,那说明延迟可能较大,需要从MASTER上取得binlog status,判断当前的binlog和MASTER上的差距;

因此,相对更加严谨的做法是:
在第三方监控节点上,对MASTER和SLAVE同时发起SHOW BINARY LOGSSHOW SLAVE STATUS\G的请求,最后判断二者binlog的差异,以及 Exec_Master_Log_PosRead_Master_Log_Pos 的差异。

例如:
在MASTER上执行SHOW BINARY LOGS 的结果是:

+------------------+--------------+
| Log_name | File_size |
+------------------+--------------+
| mysql-bin.000009 | 1073742063 |
| mysql-bin.000010 | 107374193 |
+------------------+--------------+

而在SLAVE上执行SHOW SLAVE STATUS\G 的结果是:

Master_Log_File: mysql-bin.000009
 Read_Master_Log_Pos: 668711237
Relay_Master_Log_File: mysql-bin.000009
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
***
Exec_Master_Log_Pos: 654409041

***
Seconds_Behind_Master: 3296
***

这时候,SLAVE实际的延迟应该是:
mysql-bin.000009 这个binlog中的binlog position 1073742063 和 SLAVE上读取到的binlog position之间的差异延迟,即:

1073742063 - 654409041 = 419333022 个binlog event

并且还要加上 mysql-bin.000010这个binlog已经产生的107374193个binlog event,共

107374193 + 419333022 = 526707215 个binlog event

后记更新:

1、可以在MASTER上维护一个监控表,它只有一个字段,存储这最新最新时间戳(高版本可以采用event_scheduler来更新,低版本可以用cron结合自动循环脚本来更新),在SLAVE上读取该字段的时间,只要MASTER和SLAVE的系统时间一致,即可快速知道SLAVE和MASTER延迟差了多少。不过,在高并发的系统下,这个时间戳可以细化到毫秒,否则哪怕时间一致,也是有可能会延迟数千个binlog event的。
2、网友(李大玉,QQ:407361231)细心支出上面的计算延迟有误,应该是mysql-bin.000009的最大事件数减去已经被执行完的事件数,即1073742063 – 654409041= 419333022个binlog event,再加上mysql-bin.000010这个binlog已经产生的107374193个binlog event,共526707215 个binlog event。

[MySQL FAQ]系列 — 5.6版本GTID复制异常处理一例

昨天处理了一个MySQL 5.6版本下开启GTID模式复制异常案例,MASTER上的任何操作都无法在SLAVE上应用,SLAVE的RELAY LOG里有记录,但SLAVE的BINLOG却找不到蛛丝马迹。由于开启了GTID,所以排查起来也简单,只需要在SLAVE上把RELAY LOG和BINLOG分别解析成文本文件,再直接搜索MASTER的UUID,就能找到SLAVE上是否应用了MASTER复制过来的事务。 排查过程中,曾经一度怀疑是因为设置了BINLOG-DO或者IGNORE规则,或者设置了REPLICATION-DO或IGNORE规则,甚至是GTID的严重BUG,但都没发现端倪。直到从 SHOW SLAVE STATUS 里发现下面这个信息:

[yejr@imysql.com]> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
...
              Master_Log_File: mysql-bin.000001
          Read_Master_Log_Pos: 2539
               Relay_Log_File: mysql-relay-bin.000003
                Relay_Log_Pos: 1996
        Relay_Master_Log_File: mysql-bin.000001
             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: 2539
# 无论binlog file 还是 pos,都和MASTER保持一致,也就是说BINLOG的接收和RELAYR LOG的APPLY都很正常,有条不紊工作着
              Relay_Log_Space: 2778
              Until_Condition: None
               Until_Log_File:
                Until_Log_Pos: 0
...
        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:
# 没设置忽略某些 server-id 上的BINLOG
             Master_Server_Id: 123315
                  Master_UUID: 35cc99c6-0297-11e4-9916-782bcb2c9453
             Master_Info_File: /data/db11_3316/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: 4294967295
                  Master_Bind:
      Last_IO_Error_Timestamp:
     Last_SQL_Error_Timestamp:
               Master_SSL_Crl:
           Master_SSL_Crlpath:
           Retrieved_Gtid_Set: 35cc99c6-0297-11e4-9916-782bcb2c9453:1-451
            Executed_Gtid_Set: 35cc99c6-0297-11e4-9916-782bcb2c9453:1-2455:792490-4517929
                Auto_Position: 1

从上面的日志发现什么了没?尤其是这两行:

           Retrieved_Gtid_Set: 35cc99c6-0297-11e4-9916-782bcb2c9453:1-451
            Executed_Gtid_Set: 35cc99c6-0297-11e4-9916-782bcb2c9453:1-2455:792490-4517929
                Auto_Position: 1

这下有点明白了吧,意思是:

1、SLAVE从MASTER上复制了GTID范围是:1-451;
2、SLAVE上执行GTID的范围分为两段,一段是:1-2455,另一段是:792490-4517929;

尼玛,不应该是连续的嘛,怎么会这么奇葩⊙﹏⊙b,这可如何是好呀,好捉急~~~ 莫急,且容我们慢慢分析为啥GTID从MASTER到SLAVE之后发生了断点,产生了间隙。

正常滴,在MySQL 5.6启用GTID后,部署REPLICATION复制时,可以设定 MASTER_AUTO_POSITION = 1,让 SLAVE 根据 GTID 自动选择适当的事务点进行复制,DBA基本上无需关注和担心主从不一致的问题,还是很让DBA省心的。 在启用 MASTER_AUTO_POSITION = 1 的情况下,正常是不会发生 GTID 中间有个空隙,产生断点的问题发生。除非是下面这种情况:

1、人工暂停SLAVE进程;
2、MASTER上继续写入数据;
3、MASTER上刷新LOG;
4、MASTER上删除旧BINLOG,只保留最新的BINLOG;
5、SLAVE上启动MASTER,这时候会报错,像下面这样:
Last_IO_Errno: 1236
Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires.'

针对这种问题的处理方法可以这么做:

1、关闭MASTER_AUTO_POSITION,即设置 MASTER_AUTO_POSITION = 0;
2、手工CHANGE BINLOG FILE & POS;

这种情况下,不能再次设置 MASTER_AUTO_POSITION = 1,否则还会再次报错。 还有一种情况会发生 GTID 间隙断点问题,例如这样:

1、正常配置 REPLICATION 复制,但是设置 MASTER_AUTO_POSITION = 0,也就是人工指定 BINLOG FILE & POS的传统方法;
2、在复制过程中,暂时关闭 SLAVE 进程;
3、手工修改 BINLOG FILE & POS 信息,指向新的 BINLOG FILE & POS 点;
4、启动SLAVE,这时候就会发现 GTID 断点的现象重现了;

在主从高可用模式下,可能主从间会发生切换,然后再次切换回来,这时候也可能发生上述的断点问题。因此我们建议采用双主来部署高可用切换,基本上可以实现任意来回切换,无需手工指定新的 BINLOG FIEE & POS 信息。

还有最后一种情况,就是在 MASTER 上执行了 RESET MASTER,导致 MASTER 上的 BINLOG FILE & POS 全部重置,SLAVE 上读取到的信息自然也就不一致了。

好了,说了那么多,我们最后来说下如何应对处理 GTID 断点的问题。

方法一:手工修改 BINLOG FILE & POS

1、关闭SLAVE;
2、手工CHANGE BINLOG FILE & POS,指向MASTER上最新产生的BINLOG FILE & POS,并且设置 MASTER_AUTO_POSITION = 0;
3、启动SLAVE;

方法二:手工修改 GTID_PURGED 值

1、关闭 SLAVE;
2、在 SLAVE 上执行 RESET MASTER,重设 SLAVE 上的 BINLOG FILE & POS(如果这个节点用于复制中继,要注意所有binlog是否都被读取完毕,避免数据丢失);
3、在 SLAVE 上执行 SET @@GLOBAL.GTID_PURGED = '35cc99c6-0297-11e4-9916-782bcb2c9453:1-2455';
4、启动 SLAVE;

这种做法比较费解一点,意思是,我们告诉SLAVE要主动抛弃掉 MASTER 上传输过来的某些区间的事务。在这个例子中,我们抛弃了 1-2455 这个区间,也就是在 GTID 从 2466 开始,又会继续应用 RELAY LOG 了,相比我们最开始的那个信息:

           Retrieved_Gtid_Set: 35cc99c6-0297-11e4-9916-782bcb2c9453:1-451
            Executed_Gtid_Set: 35cc99c6-0297-11e4-9916-782bcb2c9453:1-2455:792490-4517929

我们强制 SLAVE 只忽略 1-2455 这个区间,从 2466 开始继续复制,消除了本来也会被忽略的区间: 792490-4517929,确保新产生的事务都会被继续应用。这个做法可以参考MySQL手册:Excluding transactions with gtid_purged

还有另外一种费力不讨好的做法,就是在 MASTER 上执行一些没用的空事务,使得 GTID 的序号一直在加大,直到超过 2555 为止,然后在 792490-4517929 这个区间依法炮制一番,但我们非常不推荐采用这种做法,既麻烦又容易误操作。 说了这么多,在 MySQL 5.6及以上版本中,我们强烈建议启用 MASTER_AUTO_POSITION = 1,让 MySQL 自己去做判断,减少一些不必要的问题,并且采用双主(其中一个主设为只读)的方式,方便两个主之间可以随意相互切换,而不必担心数据不一致。

上面过程我采用的MySQL版本:5.6.17-65.0-rel65.0-log Percona Server with XtraDB (GPL), Release rel65.0, Revision 587,实际案例发生的MySQL版本当时忘了记录了,但肯定也是5.6以上的啦,哈哈~~~

[MySQL FAQ]系列 — 大数据量时如何部署MySQL Replication从库

我们在部署MySQL Replication从库时,通常是一开始就做好一个从库,然后随着业务的变化,数据也逐渐复制到从服务器。

但是,如果我们想对一个已经上线较久,有这大数据量的数据库部署复制从库时,应该怎么处理比较合适呢?

本文以我近期所做Zabbix数据库部署MySQL Replication从库为例,向大家呈现一种新的复制部署方式。由于Zabbix历史数据非常多,在转TokuDB之前的InnoDB引擎时,已经接近700G,转成TokuDB后,还有300多G,而且主要集中在trends_uint、history_uint等几个大表上。做一次全量备份后再恢复耗时太久,怕对主库写入影响太大,因此才有了本文的分享。

我大概分为几个步骤来做Zabbix数据迁移的:

1、初始化一个空的Zabbix库

2、启动复制,但设置忽略几个常见错误(这几个错误代码对应具体含义请自行查询手册)
#忽略不重要的错误,极端情况下,甚至可以直接忽略全部错误,例如
#slave-skip-errors=all
slave-skip-errors=1032,1053,1062

3、将大多数小表正常备份导出,在SLAVE服务器上导入恢复。在这里,正常导出即可,无需特别指定 --master-data 选项

4、逐一导出备份剩下的几个大表。在备份大表时,还可以分批次并发导出,方便并发导入,使用mysqldump的"-w"参数,然后在SLAVE上导入恢复(可以打开后面的参考文章链接)

5、全部导入完成后,等待复制没有延迟了,关闭忽略错误选项,重启,正式对外提供服务

上述几个步骤完成后,可能还有个别不一致的数据,不过会在后期逐渐被覆盖掉,或者被当做过期历史数据删除掉。

本案例的步骤并不适用于全部场景,主要适用于:

不要求数据高一致性,且数据量相对较大,尤其是单表较大的情况,就像本次的Zabbix数据一样。

参考文章:

迁移Zabbix数据库到TokuDB

[MySQL FAQ]系列— mysqldump加-w参数备份