如何得到Slave应用relay-log的时间

Posted 醒嘞

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了如何得到Slave应用relay-log的时间相关的知识,希望对你有一定的参考价值。

官方社区版mysql 5.7.19 基于Row+Position搭建的一主一从传统复制结构:Master->{Slave}

ROLE HOSTNAME BASEDIR DATADIR IP PORT
Master ZST1 /usr/local/mysql /data/mysql/mysql3307/data 192.168.85.132 3307
Slave ZST2 /usr/local/mysql /data/mysql/mysql3307/data 192.168.85.133 3307

最初是想核实延迟复制的master_delay=N以哪个时间作为基准计算,想到如果在Slave的表中添加一个以current_timestamp为默认值的时间列,从库在应用relay-log时将"当前"时间写入。将它和表中原来的时间字段作对比,就可以知道延迟时间。想法貌似不错,但...自以为是...很悲催~

技术分享图片
# 测试表结构
mydba@192.168.85.133,3307 [replcrash]> show create table py_user;
+---------+----------------------------------------------+
| Table   | Create Table                                 |
+---------+----------------------------------------------+
| py_user | CREATE TABLE `py_user` (
  `uid` int(11) NOT NULL AUTO_INCREMENT,
  `name` varchar(32) DEFAULT NULL,
  `add_time` datetime DEFAULT CURRENT_TIMESTAMP,
  `server_id` varchar(10) DEFAULT NULL,
  PRIMARY KEY (`uid`)
) ENGINE=InnoDB AUTO_INCREMENT=4105 DEFAULT CHARSET=utf8 |
+---------+----------------------------------------------+
1 row in set (0.00 sec)

# Slave开启延迟复制
mydba@192.168.85.133,3307 [replcrash]> change master to master_delay = 30;
# 添加参考列
mydba@192.168.85.133,3307 [replcrash]> alter table py_user add ins_time datetime default current_timestamp;
View Code

然后往Master写入新数据,并到Slave查看数据

技术分享图片
# Slave数据
mydba@192.168.85.133,3307 [replcrash]> select * from py_user;
+-----+--------------------------+---------------------+-----------+---------------------+
| uid | name                     | add_time            | server_id | ins_time            |
+-----+--------------------------+---------------------+-----------+---------------------+
|   1 | BD9U7I9W68BTDIXWEEUQNYRX | 2017-12-19 11:07:40 | 1323307   | 2017-12-19 11:07:40 |
|   2 | 9722XBCKISXDBSRDA5VA0A   | 2017-12-19 11:07:42 | 1323307   | 2017-12-19 11:07:42 |
+-----+--------------------------+---------------------+-----------+---------------------+
2 rows in set (0.00 sec)

# general-log
[[email protected] data]# cat mysql-general.log 
/usr/local/mysql/bin/mysqld, Version: 5.7.19-log (MySQL Community Server (GPL)). started with:
Tcp port: 3307  Unix socket: /tmp/mysql3307.sock
Time                 Id Command    Argument
...
2017-12-19T03:07:46.515218Z        17 Query     truncate table py_user
2017-12-19T03:08:10.516900Z        17 Query     BEGIN
2017-12-19T03:08:10.517318Z        17 Query     COMMIT /* implicit, from Xid_log_event */
2017-12-19T03:08:12.517930Z        17 Query     BEGIN
2017-12-19T03:08:12.518383Z        17 Query     COMMIT /* implicit, from Xid_log_event */
2017-12-19T03:08:27.614844Z         3 Query     select * from py_user
[[email protected] data]# 
View Code

general-log可以看出Slave确实是晚于Master 30秒才应用,但新写入的记录对应的ins_time并没有滞后add_time 30秒
为什么会出现这种情况?解析relay-log查看日志中是如何记录的

技术分享图片
# Slave上的relay-log信息
[[email protected] data]# mysqlbinlog -v -vv --base64-output=decode-rows relay-bin.000009
...
# at 2803
#171219 11:07:42 server id 1323307  end_log_pos 19664 CRC32 0x6fdfa523  Query   thread_id=26    exec_time=0     error_code=0
SET TIMESTAMP=1513652862/*!*/;
BEGIN
/*!*/;
# at 2888
#171219 11:07:42 server id 1323307  end_log_pos 19727 CRC32 0x9edb1d95  Table_map: `replcrash`.`py_user` mapped to number 231
# at 2951
#171219 11:07:42 server id 1323307  end_log_pos 19803 CRC32 0x18252616  Write_rows: table id 231 flags: STMT_END_F
### INSERT INTO `replcrash`.`py_user`
### SET
###   @1=2 /* INT meta=0 nullable=0 is_null=0 */
###   @2=9722XBCKISXDBSRDA5VA0A /* VARSTRING(96) meta=96 nullable=1 is_null=0 */
###   @3=2017-12-19 11:07:42 /* DATETIME(0) meta=0 nullable=1 is_null=0 */
###   @4=1323307 /* VARSTRING(30) meta=30 nullable=1 is_null=0 */
# at 3027
#171219 11:07:42 server id 1323307  end_log_pos 19834 CRC32 0x5e49e8d9  Xid = 295
COMMIT/*!*/;

# Slave上的binlog信息
[[email protected] logs]# mysqlbinlog -v -vv --base64-output=decode-rows mysql-bin.000005
...
# at 19029
#171219 11:07:42 server id 1323307  end_log_pos 19100 CRC32 0x70e91679  Query   thread_id=26    exec_time=30    error_code=0
SET TIMESTAMP=1513652862/*!*/;
BEGIN
/*!*/;
# at 19100
#171219 11:07:42 server id 1323307  end_log_pos 19165 CRC32 0x9fcf7ba6  Table_map: `replcrash`.`py_user` mapped to number 231
# at 19165
#171219 11:07:42 server id 1323307  end_log_pos 19246 CRC32 0x17e542da  Write_rows: table id 231 flags: STMT_END_F
### INSERT INTO `replcrash`.`py_user`
### SET
###   @1=2 /* INT meta=0 nullable=0 is_null=0 */
###   @2=9722XBCKISXDBSRDA5VA0A /* VARSTRING(96) meta=96 nullable=1 is_null=0 */
###   @3=2017-12-19 11:07:42 /* DATETIME(0) meta=0 nullable=1 is_null=0 */
###   @4=1323307 /* VARSTRING(30) meta=30 nullable=1 is_null=0 */
###   @5=2017-12-19 11:07:42 /* DATETIME(0) meta=0 nullable=1 is_null=0 */
# at 19246
#171219 11:07:42 server id 1323307  end_log_pos 19277 CRC32 0x8557b6ea  Xid = 249
COMMIT/*!*/;
View Code

在relay-log/binlog中可以看到SET TIMESTAMP=1513652862/*!*/;

技术分享图片
mydba@192.168.85.133,3307 [replcrash]> set timestamp=1513652862;select now();set timestamp=0;select now();
Query OK, 0 rows affected (0.00 sec)

+---------------------+
| now()               |
+---------------------+
| 2017-12-19 11:07:42 |
+---------------------+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.00 sec)

+---------------------+
| now()               |
+---------------------+
| 2017-12-20 10:48:49 |
+---------------------+
1 row in set (0.00 sec)

mydba@192.168.85.133,3307 [replcrash]> 
View Code

正是由于设置了TIMESTAMP,从库ins_time列使用current_timestamp默认值时就得到当时的时间。SBR的环境中,时间相关的函数(now(),current_date(),current_time()等),都能安全的复制到Slave的原因也是因为binlog中记录有timestamp
因此上面添加列获取Slave应用relay-log的时间肯定行不通。如果只是偶尔查看的话,可以从general-log中提取~.~

master_delay = N
An event received from the master is not executed until at least N seconds later than its execution on the master. The exceptions are that there is no delay for format description events or log file rotation events, which affect only the internal state of the SQL thread.

以上是关于如何得到Slave应用relay-log的时间的主要内容,如果未能解决你的问题,请参考以下文章

MySQL主从同步(复制)的配置

MYSQL---主从同步概述与配置

关于Relay Log无法自动删除的问题

reset slave all更彻底

Mysql面试题

修改hostname导致mysql重启slave失败的修复方法