如何得到Slave應用relay-log的時間
阿新 • • 發佈：2017-12-20
rim 參考 is_null ble close sele ont write nullable
官方社區版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以哪個時間作為基準計算
# 測試表結構 mydba@192.168.85.133,3307 [replcrash]> show create table py_user; +---------+----------------------------------------------+ | Table | Create Table |View Code+---------+----------------------------------------------+ | 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;
然後往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 [root@ZST2 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 [root@ZST2 data]#View Code
general-log可以看出Slave確實是晚於Master 30秒才應用，但新寫入的記錄對應的ins_time並沒有滯後add_time 30秒
為什麽會出現這種情況？解析relay-log查看日誌中是如何記錄的
# Slave上的relay-log信息 [root@ZST2 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信息 [root@ZST2 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的時間